안녕하세요. 유경상 입니다. NeoDEEX에는 유연하고 사용하기 간편한 로깅 기능으로 Fox Logging을 제공합니다. Fox Logging은 IFoxLog 인터페이스를 사용하여 다양한 매체(console, debugger, text file, database 등)에 로그를 기록할 수 있습니다.
Fox Logging은 기본으로 제공되는 로거의 차이만 있을 뿐 NeoDEEX의 모든 에디션(Enterprise, Standard, Free)에서 사용이 가능합니다. 이번 포스트에서는 Fox Logging과 로깅 프레임워크로 많이 사용되는 log4net의 성능을 간단히 비교해 보고자 합니다. 결론부터 빠르게 이야기 하자면, 파일 로깅 환경에서 Fox Logging은 log4net 보다 60% 이상 성능이 더 우수합니다.
시작하기 전에…
성능 비교를 하기 전에 저는 log4net에 대한 깊은 지식을 가지고 있지 않음을 미리 밝혀 둡니다. log4net 공식 웹 사이트의 자료와 온라인 도움말 정도만을 참고하여 테스트 코드를 작성하였지만 성능을 높이기 위해 보다 나은 코딩 패턴이 존재할 수도 있습니다. 따라서 포스트를 읽으면서 성능 비교에 이의가 있으신 분은 곧바로 알려주시면 반영하도록 하겠습니다.
또 한가지 고려할 사항은 Fox Logging과 log4net의 기능 범위에 대한 사항입니다. log4net은 Fox Logging에 비해 많은 기능을 보유하고 있습니다. 예를 들어, log4net은 로그 메시지의 포맷팅(log4net에서는 layout)을 자유롭게 지정할 수 있지만 Fox Logging은 제약이 따릅니다. 또 log4net은 기본적으로 로깅 문맥(logging context)을 통해 사용자 정보와 같은 로깅 시점의 추가 정보를 사용할 수 있습니다만 Fox Logging은 이러한 정보에 접근하기 위해서는 추가적인 코드를 작성해야 합니다. 다시 말해 지원하는 기능의 범위가 다르기 때문에 로깅 프레임워크의 복잡도가 다르며 이로 인해 기본적인 성능 차이가 발생할 수 있다는 점입니다.
테스트 환경
테스트 환경은 결과가 전혀 다르게 나올 정도로 성능 테스트에서 중요한 요소 중 하나 입니다. 따라서 테스트에 사용된 환경을 최대한 상세히 기술하도록 하겠습니다.
하드웨어 및 운영체제
테스트에 사용한 컴퓨터는 저의 노트북이며 사양은 다음과 같습니다.
- CPU: Intel i7 Q820 (1.83GHz Turbo 3.06GHz, 8MB Cache)
- RAM: DDR3 8GB
- HDD: Intel SSD 330 Serise 240GB (SATA2 인터페이스)
Hitachi HTS541616J9SA00 5400RPM 160GB (USB 2.0 인터페이스) - OS: Windows 8 Pro x64
테스트 방법에서 언급하겠지만 로깅 매체가 파일, 즉 디스크이기 때문에 어떤 하드 디스크를 사용했는가에 따라 성능 테스트의 결과에 차이가 발생할 수 있습니다. 제 노트북은 SSD 2개가 설치되어 있기 때문에 느린 디스크를 상정하기 위해 USB 2.0으로 연결된 일반 하드 디스크도 사용하여 테스트 했습니다.
소프트웨어
테스트에 사용한 소프트웨어, 특히 비교 대상이 되는 두 로깅 프레임워크는 NuGet을 통해 손쉽게 구할 수 있는 것을 선택하였습니다.
테스트 방법
테스트 방법이 가장 고민이었는데, 그 이유는 앞서 언급한 대로 log4net과 Fox Logging이 제공하는 기능의 범위가 다르기 때문이었습니다. 고민 결과 두 로깅 프레임워크에서 공통적으로 제공하는 기능이면서 서로 유사하며 가장 많이 사용되는 기능을 사용하여 테스트하는 것이 가장 좋은 것으로 판단되었습니다. 즉, 텍스트 파일에 로그를 기록하는 파일 로깅으로 두 로깅 프레임워크의 성능을 비교하는 방법을 선택하였습니다.
테스트 코드
로그를 기록하는 코드 패턴은 로그 관리자로부터 로거를 획득(GetLogger)하고 획득한 로거에 로그 메시지를 기록하는 방식입니다. 일반적으로 로그를 기록하는 코드는 어플리케이션 전반에 걸쳐 흩어져 있으며 로거를 필요할 때마다 획득하는 방식을 사용하기 때문입니다. 로거를 얼마나 빠르게 획득하는가도 로깅 프레임워크의 성능 측면에서 중요한 팩터이기도 합니다.
또한, 로그 메시지를 생성(예를 들어 포맷팅)하는데 소요되는 비용(cost)에 의해 로깅 자체의 성능이 영향 받지 않도록 텍스트 로그 메시지를 테스트 전에 생성해 놓았으며 이렇게 생성된 로그 메시지를 단순히 로거에 기록하도록 하였습니다. 테스트에 사용된 코드는 다음 링크에서 다운로드 할 수 있습니다.
테스트 전체 소스 코드 링크 (log4net, NeoDEEX4 Free Edition은 NuGet으로 설치 필요)
다음 코드는 테스트에 사용된 핵심 초기화 코드와 로그 기록 코드 입니다.
// 초기화
static void Init()
{
// log4net 구성 설정
XmlConfigurator.Configure(new FileInfo("log4net.xml"));
// 로그 메시지 생성
for (int i = 0; i < MaxLogCount; i++)
{
TextLogEntryTable[i] = String.Format("Log entry #{0:#,###,##0}", i);
}
// 로거 이름 설정
LoggerName = typeof(Program).FullName;
}
// log4net
static void LogWithLog4Net(int index)
{
ILog log = LogManager.GetLogger(LoggerName);
log.Info(TextLogEntryTable[index]);
}
// Fox Logging
static void LogWithFoxLogging(int index)
{
IFoxLog log = FoxLogManager.GetLogger(LoggerName);
log.Information(TextLogEntryTable[index]);
}
실제 테스트는 단일 스레드가 100,000(10만) 회의 루프를 돌면서 LogWithLog4Net 메서드 혹은 LogWithFoxLogging 메서드를 호출하여 소요되는 시간을 측정하였습니다. 물론, JIT 컴파일이나 파일 로드 등의 부수 효과가 발생하지 않도록 1000 회의 워밍업 로그 기록을 먼저 수행했습니다. 다음은 log4net에 대한 성능 테스트 코드 입니다. Fox Logging의 경우에는 LogWithLog4Net 메서드 호출 대신 LogWithFoxLogging 메서드 호출을 사용합니다.
// log4net 테스트
Console.WriteLine("Writing {0:#,###,##0} log entries with log4net......", MaxLogCount);
Stopwatch watch1 = new Stopwatch();
watch1.Start();
for (int i = 0; i < MaxLogCount; i++)
{
LogWithLog4Net(i);
}
watch1.Stop();
long perf1 = MaxLogCount * 1000 / watch1.ElapsedMilliseconds;
Console.WriteLine("\t{0,9:#,##0.000} sec", watch1.ElapsedMilliseconds / 1000.0);
Console.WriteLine("\t{0,9:#,###,##0} logs/sec", perf1);
단일 스레드가 아닌 복수의 스레드가 동시에 로그를 남기는 경우에는, 로그에 대한 잠금(lock) 처리로 인해 성능 저하가 발생합니다만 이 테스트에서는 다중 스레드 테스트는 제외하였습니다. 다중 스레드를 테스트 하고자 한다면 위 코드의 for 문장 대신 Parallel.For 메서드를 사용하면 됩니다.
Parallel.For(0, MaxLogCount, index => { LogWithLog4Net(index); });
로깅 설정
앞서 언급한 대로 log4net과 Fox Logging이 모두 텍스트 파일에 로그를 기록하도록 로거 설정을 사용하였습니다. log4net은 RollingFileAppender를 사용하였는데 Fox Logging의 FoxTextFileLogger가 날짜 혹은 파일 크기에 따라 파일을 제어하는 기능이 있기 때문에 가장 유사한 로거로써 RollingFileAppender를 선택했습니다. 단순한 파일 로깅을 수행하는 FileAppender는 RollingFileAppender에 비해 성능이 더 우수합니다.
다음은 log4net에 사용된 로거 구성 설정 입니다. log4net의 로거 구성 설정 중 layout 설정이 성능과 영향이 있습니다. Layout은 로그에 기록될 로그 메시지의 포맷을 지정하는데 Layout 구성에 기록할 내용이 많을수록 성능은 떨어집니다. 공평한 비교를 위해 Fox Logging 이 생성하는 텍스트와 가장 비슷하도록 구성하였습니다.
<?xml version="1.0" encoding="utf-8" ?>
<log4net>
<appender name="RollingFile" type="log4net.Appender.RollingFileAppender">
<file value="log4net.log" />
<appendToFile value="true" />
<datePattern value="-yyyy-MM-dd" />
<rollingStyle value="Date" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%p %d [%c] %m%n" />
</layout>
</appender>
<root>
<level value="DEBUG" />
<appender-ref ref="RollingFile" />
</root>
</log4net>
다음은 Fox Logging에 사용된 로거 구성 설정입니다.
<?xml version="1.0" encoding="utf-8" ?>
<theone.configuration xmlns="http://schema.theonetech.co.kr/fx/config/2011/04/">
<logging filter="Verbose">
<providers />
<loggers>
<logger name="LogPerfTest.Program" provider="FoxTextFileLoggerProvider">
<property name="directory" value="."/>
<property name="fileprefix" value="NeoDEEX"/>
</logger>
</loggers>
</logging>
</theone.configuration>
로그 파일 내용
위와 같은 구성 설정에 의해 생성되는 로그 메시지들은 다음과 같습니다. 10만개의 로그 엔트리를 기록하는 경우, log4net은 약 6.66MB, Fox Logging은 약 6.53MB 크기의 로그 파일을 생성하여 두 로그 파일의 크기는 비슷합니다.
// log4net.log 파일
INFO 2012-09-20 00:42:27,328 [LogPerfTest.Program] Log entry #0
INFO 2012-09-20 00:42:27,438 [LogPerfTest.Program] Log entry #1
INFO 2012-09-20 00:42:27,438 [LogPerfTest.Program] Log entry #2
INFO 2012-09-20 00:42:27,438 [LogPerfTest.Program] Log entry #3
......
// NeoDEEX_2012-mm-dd.log 파일
I 2012-09-20 00:42:27.43662 [LogPerfTest.Program] Log entry #0
I 2012-09-20 00:42:27.43862 [LogPerfTest.Program] Log entry #1
I 2012-09-20 00:42:27.43862 [LogPerfTest.Program] Log entry #2
I 2012-09-20 00:42:27.43862 [LogPerfTest.Program] Log entry #3
......
테스트 결과
테스트는 5회 테스트한 결과를 평균했으며, 빠른 디스크(SSD)와 일반 디스크에 대해 각각 테스트 했습니다. SSD와 같은 빠른 디스크에 대해 파일 로그를 남기는 경우 Fox Logging이 56% ~ 76% 정도 우수한 성능을 발휘했으며 평균적으로 66.66% 정도 우수했습니다. 즉, Fox Logging의 파일 로깅은 초당 약 13만개의 로그를 남기는 반면 log4net은 ���당 약 8만개 정도의 로그를 남길 수 있었습니다.
| SSD 테스트 |
log4net |
로그개수 |
Fox Logging |
비교 |
| 시간(초) |
logs/sec |
시간(초) |
logs/sec |
| 1 |
1.336 |
74,850 |
100000 |
0.818 |
122,249 |
63.33% |
| 2 |
1.316 |
75,987 |
100000 |
0.760 |
131,578 |
73.16% |
| 3 |
1.244 |
80,385 |
100000 |
0.753 |
132,802 |
65.21% |
| 4 |
1.368 |
73,099 |
100000 |
0.776 |
128,865 |
76.29% |
| 5 |
1.234 |
81,037 |
100000 |
0.789 |
126,742 |
56.40% |
| 평균 |
1.300 |
77,072 |
100000 |
0.779 |
128,447 |
66.66% |
일반 HDD의 경우, 디스크에 기록하는 시간이 느려지므로 파일 로깅의 성능은 SSD 보다 떨어지는 것이 당연합니다. 특히, 이 테스트에서는 USB 2.0으로 연결된 외장 하드(5400RPM의 2.5인치 디스크)이기 때문에 더욱 성능저하가 뚜렷합니다. SSD에 비해 log4net은 약 30%, Fox Logging은 약 33%의 성능 저하가 발생합니다. 그러나 여전히 Fox Logging은 log4net에 비해 평균 61% 더 빠른 성능을 보여주고 있습니다.
| HDD 테스트 |
log4net |
로그개수 |
Fox Logging |
비교 |
| 시간(초) |
logs/sec |
시간(초) |
logs/sec |
| 1 |
1.882 |
53,134 |
100000 |
1.153 |
86,730 |
63.23% |
| 2 |
1.825 |
54,794 |
100000 |
1.145 |
87,336 |
59.39% |
| 3 |
1.945 |
51,413 |
100000 |
1.130 |
88,495 |
72.13% |
| 4 |
1.886 |
53,022 |
100000 |
1.171 |
85,397 |
61.06% |
| 5 |
1.799 |
55,586 |
100000 |
1.188 |
84,175 |
51.43% |
| 평균 |
1.867 |
53,590 |
100000 |
1.157 |
86,427 |
61.27% |
앞서 언급한 대로 log4net의 성능은 로그 메시지를 어떤 포맷(Layout)으로 기록하느냐에 따라 성능이 달라 집니다. 로그 레벨(INFO, DEBUG, ERROR 등)과 로그 메시지만을 기록하는 SimpleLayout을 사용하면 log4net은 초당 10만개 정도의 로그를 기록할 수 있습니다. 하지만 로그 레벨, 날짜, 시간, 로그 소스를 기록하는 Fox Logging은 여전히 약 27% 정도 더 빠릅니다. 이 테스트 결과는 상세한 표를 생략하겠습니다.
기능을 희생하여 RollingFileAppender 대신 FileAppender를 사용하면 log4net의 성능이 향상됩니다. 하지만 여전히 Fox Logging은 SSD 디스크 환경에서 FileAppender를 사용하는 log4net에 비해 약 50% 더 빠르며 SimpleLayout을 사용하더라도 20%이상 더 빠릅니다(SSD 기준). 이 테스트 결과 역시 상세한 표는 생략하겠습니다.
다중 스레드가 로그를 남기는 테스트에서는 Fox Logging의 스레드 동기화 및 잠금 메카니즘으로 인해 Fox Logging의 성능이 약간 감소합니다. 하지만 Fox Logging은 여전히 log4net에 비해 40% 이상 더 빠릅니다(SSD 기준). 이 테스트 결과 역시 상세한 표는 생략하겠습니다.
이 외에도 재미있는 테스트 결과는 두 로깅 프레임워크의 필터링 테스트 입니다. 로깅에서 필터링은 상당히 중요한 성능 요소 입니다. 일반적으로 로그의 양을 줄이거나 늘이는데 소스 코드를 수정하지 않고 구성 설정의 로그 레벨을 올리거나 내리기 때문입니다. 이 테스트에서도 log4net과 Fox Logging의 로그 레벨을 Error 수준으로 상승 시켜 코드에서 남기는 Information 레벨의 로그가 모두 필터링 되도록 하는 것입니다. 이 테스트에서 log4net은 약 200 msec 정도의 소요 시간을 나타냈고 Fox Logging은 약 10 msec의 소요 시간을 나타냈습니다. 즉, log4net은 초당 50만개 정도의 로그를 필터링 할 수 있는 반면 Fox Logging은 약 1천 만개의 로그를 필터링 할 수 있다는 이야기 입니다.
결론
Fox Logging은 NeoDEEX 4.0이 제공하는 유연하고 빠른 로깅 프레임워크 입니다. 비슷한 설정의 파일 로깅에 있어서 Fox Logging은 log4net에 비해 40%~60% 이상 성능이 더 우수합니다. 또한 Fox Logging은 log4net에 비해 로그를 매우 빠르게 필터링 하기 때문에 어플리케이션의 성능을 크게 저하시키지 않으면서 디버깅, 진단 등의 목적으로 많은 로그를 남길 수 있습니다. 물론 이 결과는 테스트 환경에 따라서 달라질 수 있습니다.
log4net은 오랫동안 사용되어온 입증되고 성공적이며 강력한 로깅 프레임워크임에 틀림이 없습니다. Fox Logging이 제공하지 않는 풍부한 기능을 가지고 있으므로, 파일 로깅에서 Fox Logging의 성능이 우수하기 때문에 Fox Logging이 log4net에 비해 좋다고 단순 비교하긴 어렵습니다. 또, 데이터베이스에 로그를 기록하는 다른 로거를 사용하면 성능 차이가 없거나 log4net의 성능이 더 우수할 수도 있습니다. 다만, 어플리케이션들이 가장 흔하게 사용하는 로깅 중 하나인 파일 로깅에서는 Fox Logging의 성능이 log4net 보다 우수하다고 말할 수 있겠습니다. 이는 NeoDEEX의 철학이자 Fox Logging의 설계 모티브인 유연성, 사용 편의성, 우수한 성능이 잘 반영되어 있다고 하겠습니다. (조금 뻘쭘 하군요…)
log4net의 다양한 로깅 기능이 필요하다면 Fox Logging을 통해서 log4net을 사용하는 것도 충분히 가능합니다. Fox Logging은 유연하니까요. Fox Logging을 통해 log4net을 이용하는 구체적인 방법에 대해서는 다른 포스트를 통해 소개하도록 하겠습니다.
감사합니다.
경고 : 이 글을 무단으로 복제/스크랩하여 타 게시판, 블로그에 게시하는 것은 허용하지 않습니다.