Wednesday, November 4, 2009

Log Timmer

One common challenge in developing software is tuning performance. The application is running slow but you are not sure what is causing the problem. An approach to the debugging the problem is to use logging. This works, but you end up doing a lot of time arithmetic to determine how long it took some action to complete. Logging also adds many lines of code to the application muddling up the implementation and making it harder to read and understand. The solution is a class designed to time and log an event. I give credit to Scott Plichta for designing the architecture for the Log Timer.

Creating a log in C++ is easy. The constructor starts the timer and the destructor calculates the elapsed time and logs the results. This is a problem in Java. In Java, destructors are may not be called until the garbage collector runs. C# also uses garbage collection, but provides the IDisposable interface. IDisposable tells the garbage collector to dispose of the object as soon as possible. That means the timings provided by a log timer class in C# are not quite as accurate as the timing in a C++ log timer class.

How do you use the log timer class work in C#? The simplest method is just to place a "using" statement creating the log timer around the code you want to time:

using (new LogTimer.LogTimer())
{
// code you want to time
}

Call that is a little more complicated allows passing in the custom message:

using (new LogTimer.LogTimer("Deserialize time: "))
{
// code you want to time
}

The code above will always log. The LogTimer class has constructors that allow passing in the number of milliseconds for logging for each of the Log4Net levels. Below is an example passing in all the level thresholds:

using (new LogTimer.LogTimer("DownloadImage GetReponse time: ", 5000, 3000, 2000, 100, 0))
{
// code you want to time
}

There are several other constructors taking different number of thresholds.  Below is the implementation of the LogTimer class in C#.

using System;
using System.Collections.Generic;
using System.Text;

using log4net.Core;
using System.Diagnostics;

namespace LogTimer
{
// based on:
// http://www.eggheadcafe.com/articles/20050625.asp
// http://www.codeproject.com/KB/cs/idispose.aspx

public class LogTimer : IDisposable
{
/// <summary>
/// Create a logger for use in this class
/// </summary>
private static readonly log4net.ILog log = log4net.LogManager.GetLogger(typeof(LogTimer));

/// <summary>
/// Used by the destructor to avoid disposing twice
/// </summary>
private bool disposed = false;

/// <summary>
/// Default message
/// </summary>
private string msg = "LogTimer: ";

/// <summary>
/// Threashold in milliseconds before issuing a debug log
/// </summary>
private readonly long debugCount = 0;

/// <summary>
/// Threashold in milliseconds before issuing a info log
/// </summary>
private readonly long infoCount = 0;

/// <summary>
/// Threashold in milliseconds before issuing a warn log
/// </summary>
private readonly long warnCount = 0;

/// <summary>
/// Threashold in milliseconds before issuing a error log
/// </summary>
private readonly long errorCount = 0;

/// <summary>
/// Threashold in milliseconds before issuing a fatal log
/// </summary>
private readonly long fatalCount = 0;

/// <summary>
/// Stopwatch to determine how long between starting and stopping
/// </summary>
private Stopwatch sw = new Stopwatch();


/// <summary>
/// Simple constructor that generates a default message for the current log level
/// </summary>
public LogTimer()
{
sw.Start();
}

/// <summary>
/// Simple constructor that generates the messages for the current log level
/// </summary>
/// <param name="message">The message to log</param>
public LogTimer(string message) : base()
{
msg = message;
}

/// <summary>
/// Most comprehensive constructor. Allows setting all the properties.
/// </summary>
/// <param name="message">Message to log</param>
/// <param name="fatal">Threshold for fatal logs</param>
/// <param name="error">Threashold for error logs</param>
/// <param name="warn">Threashold for warn logs</param>
/// <param name="info">Threashold for info logs</param>
/// <param name="debug">Threadhold for debug logs</param>
public LogTimer(string message, long fatal, long error, long warn, long info, long debug) : base()
{
msg = message;
fatalCount = fatal;
errorCount = error;
warnCount = warn;
infoCount = info;
debugCount = debug;
}

/// <summary>
/// Construct allowing setting the message and threasholds for fatal, error, warn, and info.
/// </summary>
/// <param name="message">Message to log</param>
/// <param name="fatal">Threshold for fatal logs</param>
/// <param name="error">Threashold for error logs</param>
/// <param name="warn">Threashold for warn logs</param>
/// <param name="info">Threashold for info and debug logs</param>
public LogTimer(string message, long fatal, long error, long warn, long info) : base()
{
msg = message;
fatalCount = fatal;
errorCount = error;
warnCount = warn;
infoCount = info;
debugCount = info;
}

/// <summary>
/// Construct allowing setting the message and threasholds for
/// fatal, error, and warn.
/// </summary>
/// <param name="message">Message to log</param>
/// <param name="fatal">Threshold for fatal logs</param>
/// <param name="error">Threashold for error logs</param>
/// <param name="warn">Threashold for warn, info and debug logs</param>
public LogTimer(string message, long fatal, long error, long warn) : base()
{
msg = message;
fatalCount = fatal;
errorCount = error;
warnCount = warn;
infoCount = warn;
debugCount = warn;
}

/// <summary>
/// Construct allowing setting the message and threasholds for
/// fatal and error
/// </summary>
/// <param name="message">Message to log</param>
/// <param name="fatal">Threshold for fatal logs</param>
/// <param name="error">Threashold for error, warn, info and debug logs</param>
public LogTimer(string message, long fatal, long error) : base()
{
msg = message;
fatalCount = fatal;
errorCount = error;
warnCount = error;
infoCount = error;
debugCount = error;
}

/// <summary>
/// Construct allowing setting the message and threashold
/// </summary>
/// <param name="message">Message to log</param>
/// <param name="fatal">Threshold for fatal, error, warn, info,
/// and debug logs</param>
public LogTimer(string message, long fatal) : base()
{
msg = message;
fatalCount = fatal;
errorCount = fatal;
warnCount = fatal;
infoCount = fatal;
debugCount = fatal;
}

/// <summary>
/// Actual destructor
/// </summary>
~LogTimer()
{
Dispose(false);
}

/// <summary>
/// Dispose method
/// </summary>
public void Dispose()
{
Dispose(true);
GC.SuppressFinalize(this);
}

/// <summary>
/// Dispos method
/// </summary>
/// <param name="disposing">currently disposing</param>
protected virtual void Dispose(bool disposing)
{
if (!this.disposed)
{
if (disposing)
{
sw.Stop();
long duration = sw.ElapsedMilliseconds;

// log with the highest enabled log level
// a log level is enable when IsLevelEnable and leveCount > 0
if (log.IsFatalEnabled && duration >= fatalCount)
{
log.Fatal(msg + duration.ToString());
}
else if (log.IsErrorEnabled && duration >= errorCount)
{
log.Error(msg + duration.ToString());
}
else if (log.IsWarnEnabled && duration >= warnCount)
{
log.Warn(msg + duration.ToString());
}
else if (log.IsInfoEnabled && duration >= infoCount)
{
log.Info(msg + duration.ToString());
}
else if (log.IsDebugEnabled && duration >= debugCount)
{
log.Debug(msg + duration.ToString());
}
}
}
disposed = true;
}

}
}

34 comments:

九份 said...

路過--你好嗎..很棒的BLOG.........................................

tiktok said...

視訊援交露點爆乳潮吹裸體裸照裸女愛愛無碼尋夢視訊聊天a漫a片a圖一夜情一葉情人妻激情情色寫真美女自拍辣妹自拍正妹自拍美女走光辣妹走光正妹走光脫衣秀脫衣走光色情自慰自拍成人全裸打炮

志竹 said...

色情動畫影成人色情動畫色情介紹男同志色情片男同志色情影片免費男同志網免費性圖片免費東洋影片免費的av片免費的片免費的色情卡通免費直撥網免費直撥影片免費直播短片免費長片分享區免費咪咪影片網免費是訊免費洪爺色情免費洪爺色情網免費性愛觀看影片免費性愛影片分享區免費性愛動畫免費男做愛影片免費男影片免費男優免費亞洲影片免費性小說免費性片下載免費性交貼圖免費性貼片辦公室偷情遊戲免費視訊聊天網交友戀愛進行室嘟嘟成人網

欣盈 said...

I do like ur article~!!!..................................................

嘉雯 said...

Cool blog網愛聊天室色情網站交友找啦咧免費影片成人笑話成人圖庫sexy女同志聊天室愛戀情人用品情趣爽翻天咆哮小老鼠入口85cc6k脫衣人妻sexy85c脫光光taiwansex淫女情色成人男女做愛美女做愛脫衣秀a片正妹淫蕩色情後宮040185c85c77p2p77p2p性幻想手淫18禁

JeremiahRenne332 said...

自拍短片國中自拍免費自拍小魔自拍影片做愛自拍線上台灣自拍論壇台灣自慰影片台灣色小說台灣色文學台灣色文學網台灣情kiss網台灣情網色網台灣論壇區外國色片外國色情網站外國色情影片外國免費a片外國免費色情外國免費影片外國美女做愛外國美女圖外國美女圖片外國美女寫真孕婦做愛小說孕婦做愛自拍台灣論壇小說區台灣論台台灣線上a片王台灣情論壇台灣無限圖帖成人小說 言情小說 巨乳上班族聊天室

AmiHopson瓊仁豪慧 said...

看看blog調整心情,又要來繼續工作,大家加油........................................

昱廷昱廷 said...

文章很棒~感謝!!..................................................

黃k0822oryb_card said...

As a man sows, so he shall reap. ........................................

致念 said...

人不可以求其備,必捨其所短,取其所長...............................................................

K910athrinA_Petrin0 said...

Hard day......................................................................

冠中 said...

志不立,天下無可成之事。........................................

D415_evonN_Risinger0 said...

過去的事早已消失,未來的更是渺不可知,只有現在是真實的。 ..................................................

宛AshleyRemley1218儒 said...

Subtlety is better than force. ............................................................

mckinney said...

真是太猛了,請受小弟一拜Orz(>O<)..................................................

明英 said...

人生是故事的創造與遺忘。..................................................................

洪筱婷 said...

看得見您的用心~~希望這裡愈來愈熱鬧哦~~.................................................................

萱祥 said...

Where did you purchase this product?.................................................................

黃允妏 said...

幸福不是一切,人還有責任。.................................................................

又來 said...

在莫非定律中有項笨蛋定律:「一個組織中的笨蛋,恆大於等於三分之二。」......................................................................

秋娥秋娥 said...

成熟,就是有能力適應生活中的模糊。.................................................................

香昱信張君林 said...

當一個人內心能容納兩樣相互衝突的東西,這個人便開始變得有價值了。............................................................

陳韋夏陳韋夏益東富益東富 said...

先為別人的快樂著想,是超人;先為自己的快樂著想,是凡人;使別人不快樂,自己也不快樂的,是笨人。..................................................

婷珊 said...

如果你批評他人。你就沒有時間付出愛............................................................

吳婷婷 said...

As a man sows, so he shall reap...................................................................

萱祥 said...

新手上路哦~請大家多支持^_^..................................................................

茂慧茂慧 said...

吃飽了嗎?~~~還沒下班,好餓哦............................................................

誠紋 said...

一棵樹除非在春天開了花,否則難望在秋天結果。..................................................

香昱信張君林 said...

值得一看再看的格子,多謝分享..................................................................

李吳文云威昌 said...

及時行樂-快樂不需要理由............................................................

莉璇藍 said...

Judge not of men and things at first sight................................................

莉真詹詹莉真詹詹 said...

人必須心懷希望,才會活的快樂,日子才過得充實,有意義,有朝氣,有信心。.......................................................

家唐銘 said...

憂能傷身,保重哦!............................................................

偉曹琬 said...

Seeing is believing.百聞不如一見............................................................