[intlink id=”558″],[intlink id=”555″],[intlink id=”548″]の続き。
log4net, LoggingAB, NLogを比較してみた。
名前 | DLLサイズ | 速度 | 評価 |
---|---|---|---|
log4net 1.2.10 | 270,336 bytes | 70us/行 | ハマりどころなし。よくできている。 |
NLog 1.0 | 253,952 bytes | 67us/行 | バッファリング設定しないと遅い。きめ細かい設定ができるともいえる。 |
LoggingAB Enterprise Library 3.1 | 379,728 bytes | 224us/行 | 遅い。かゆいところに手が届かない印象。 |
出力なし | 0 bytes | 51us/行 | 最速だがログ出力してない(笑) |
まとめ
個人的にはNLogが好きなんだけど、実績とか考えるとlog4net使っとくのが無難だと思う。
LogginABはおすすめできない。
log4netはたぶんユーザ数が最多。
log4j使ってた経験があるなら設定とかすぐわかる。
パフォーマンスも隙が無い。
NLogは2006年からwebサイト更新されてないように見える。
十分枯れてると思うが、ちょっと不安。好意的に見れば、枯れててバージョンアップが不要なのかも??
LoggingABは重過ぎる。自作のリスナーとか作れば改善するかもしれない。
他のEnterprise Library機能と組み合わせるときにはこれしか選択肢なし。
ログ出力機能だけがほしいのであればオーバスペック。
Microsoftやpatterns & practicesが好きなら担いで見るのもよい。
あと、設定が一番ゴチャゴチャしてる。
専用の設定エディタが付属するけど、使い心地が微妙でもどかしい。
速度比較は日付単位ローテーションファイルへの出力。
「なし」は以下の空実装でログ出力を代用したもの。
class LOG
{
public static void Info(string aMessage)
{
}
public static bool IsInfoEnabled
{
get { return true; }
}
}
テスト条件
テストに使用したプログラムは、25番目のフィボナッチ数を求めるプログラム。
class Program
{
public static void Main(string[] args)
{
int tStartTimeMillis = System.Environment.TickCount;
using (new Tracer("Trace"))
{
LOG.Info("fib(25) = " + fib(25));
}
int tEndTimeMillis = System.Environment.TickCount;
Console.WriteLine("time: " + (tEndTimeMillis - tStartTimeMillis) + "ms");
}
static long fib(long n)
{
using (new Tracer("Trace"))
{
if (n <= 1)
{
return 1;
}
return fib(n - 2) + fib(n - 1);
}
}
}
25番目のフィボナッチ数を再帰を使って計算すると、242786回の再帰呼び出しを起こす。
再帰のたびにTracerを使ってログ出力してみた。
LoggingABにはMicrosoft.Practices.EnterpriseLibrary.Logging.Tracerが実装されているのでそれを使った。
log4netとNLogにはTracerが無いので以下の自作のものを使った。
class Tracer : IDisposable
{
#if LOG4NET
private static readonly ILog LOG = LogManager.GetLogger(typeof(Tracer));
#else
private static readonly Logger LOG = LogManager.GetCurrentClassLogger();
#endif
private Stopwatch mStopwatch;
private long mStartTicks;
public Tracer(string aCategory)
{
if (LOG.IsInfoEnabled)
{
if (Trace.CorrelationManager.ActivityId.Equals(Guid.Empty))
{
Trace.CorrelationManager.ActivityId = Guid.NewGuid();
}
Trace.CorrelationManager.StartLogicalOperation(aCategory);
mStopwatch = Stopwatch.StartNew();
mStartTicks = Stopwatch.GetTimestamp();
LOG.Info("Start " + aCategory + ": Activity '" + Trace.CorrelationManager.ActivityId + "' in method '" + GetExecutingMethodName() + "' at " + mStopwatch.ElapsedTicks + " ticks");
}
}
public void Dispose()
{
if (LOG.IsInfoEnabled)
{
try
{
long tEndTicks = Stopwatch.GetTimestamp();
long tElapsedMillis = mStopwatch.ElapsedMilliseconds;
LOG.Info("End " + Trace.CorrelationManager.LogicalOperationStack.Peek() + ": Activity '" + Trace.CorrelationManager.ActivityId + "' in method '" + GetExecutingMethodName() + "' at " + tEndTicks + " ticks (elapsed time: " + tElapsedMillis + " ms)");
}
finally
{
Trace.CorrelationManager.StopLogicalOperation();
}
}
GC.SuppressFinalize(this);
}
private string GetExecutingMethodName()
{
string tResult = "Unknown";
StackTrace tStackTrace = new StackTrace(false);
for (int i = 0; i < tStackTrace.FrameCount; i++)
{
MethodBase tMethod = tStackTrace.GetFrame(i).GetMethod();
if (tMethod.DeclaringType != GetType())
{
tResult = string.Concat(tMethod.DeclaringType.FullName, ".", tMethod.Name);
break;
}
}
return tResult;
}
}
ログの出力設定はできるだけあわせたんだけど・・・。
log4net
出力
2008-03-22 06:58:09,652 [1] INFO - Start Trace: Activity '3fe83136-62f7-48a5-b57c-b643c506e753' in method 'Log4netTest.Program.fib' at 665 ticks 2008-03-22 06:58:09,652 [1] INFO - End Trace: Activity '3fe83136-62f7-48a5-b57c-b643c506e753' in method 'Log4netTest.Program.fib' at 9356634867556 ticks (elapsed time: 0 ms)
NLog
出力
2008/03/22 07:02:44,181 [1] Info - Start Trace: Activity '9b409697-f680-48fb-a868-dbcae2eadd39' in method 'NLogTest.Program.fib' at 653 ticks 2008/03/22 07:02:44,181 [1] Info - End Trace: Activity '9b409697-f680-48fb-a868-dbcae2eadd39' in method 'NLogTest.Program.fib' at 9360565483535 ticks (elapsed time: 0 ms)
LoggingAB
出力
2008/03/21 22:06:10 [5752] Start - Start Trace: Activity 'ddea2bbb-de2e-42a0-a167-1461a71b7074' in method 'LoggingABTest.Program.fib' at 9363521594110 ticks 2008/03/21 22:06:10 [5752] Stop - End Trace: Activity 'ddea2bbb-de2e-42a0-a167-1461a71b7074' in method 'LoggingABTest.Program.fib' at 9363521611483 ticks (elapsed time: 0.001 seconds)
結果
log4net | NLog +BufferingWrapper | NLog | LoggingAB | 出力なし | |
---|---|---|---|---|---|
1回目(ms) | 34008 | 32604 | 612397 | 108842 | 24742 |
2回目(ms) | 34023 | 32807 | - | 109076 | 24820 |
3回目(ms) | 34024 | 33509 | - | 108826 | 24820 |
4回目(ms) | 34008 | 32449 | - | 108686 | 24758 |
5回目(ms) | 33961 | 32417 | - | 109060 | 24741 |
平均(ms) | 34005 | 32757 | 612397 | 108898 | 24776 |
行数(行) | 485574 | 485574 | 485574 | 485574 | 485574 |
(us/行) | 70 | 67 | 1261 | 224 | 51 |
485574行あたりのファイルサイズ(bytes) | 78,426,276 | 76,485,442 | 76,485,442 | 82,784,994 | - |
(bytes/ms) | 2306 | 2335 | 125 | 760 | - |
log4netとNLogの速度は互角。LoggingABは3倍遅い。
おしまい。
0件のコメント