NLogger特點(200行代碼的日志元件):
一:不依賴于第三方插件和支援.net2.0
二:支援多線程高并發
三:支援讀寫雙緩沖對列
四:自定義日志緩沖區大小
五:支援即時觸發刷盤機制
六:先按日期再按檔案大小RollingFile日志
七:支援日志存儲位置,日志檔案字首的個性化定義
一:為什麼要特别強調不依賴于第三方插件和支援.net2.0
NLogger包括名稱空間也未超過200行代碼,可見日志是相當輕量級的,如果是依賴于第三方軟體的支援,有失輕量級的定義。
NLogger的第一個版本是基本于.net4.0開發,但是發現在實際應用的時候很難降級到.net2.0的項目,因為第一個版本用到了很多.net4.0的特性,主要表現在:
1,多線程處理是用的Task
2,記憶體資料存儲是用的Tuple<>
3,集合并發處理是用的 ConcurrentQueue
4,用了Linq文法
如此多的.net4特性降級到.net2.0,确實花費了很多時間來重構這個代碼,舉個例子:
.net2.0與.net4.0在資料集合上的運用,表現的最為不同的就是:
.net2.0 不支援集合的并發處理,如果是多線程操縱集合,必須要借助于lock來鎖定對象,然而lock後的集合就從多線程變為單線程的處理了,如此的性能很讓人沮喪。
.net4.0引入的Concurrent系列的并發集合,讓很多不會多線程程式設計的夥伴都把多線程玩的溜溜轉,性能還如此的高。
良好的日志應用元件,支援多線程高并發是必不可少的特性。先标記一下測試機的硬體環境
,不同的硬體環境對測試結果是有較大影響的。
測試代碼:
開啟10個線程,每個線程寫入10W資料,确認一下代碼中數值0的個數是否正确:
for (int count = 0; count < 10; count++)
{
Thread writeThread = new Thread(new ParameterizedThreadStart((para) =>
{
Console.WriteLine(string.Format("開啟線程{0}", para));
Stopwatch sw = new Stopwatch();
sw.Start();
for (int i = 0; i < 100000; i++)
{
NLogger.WriteLog("test_", string.Format("日志測試資料,序号:{0}", i.ToString()));
}
sw.Stop();
Console.WriteLine(string.Format("線程{0}寫入日志結束,共用時{1}毫秒", para, sw.ElapsedMilliseconds));
}));
writeThread.IsBackground = true;
writeThread.Start(count);
}
測試結果:
11秒的時間就把100W條資料刷到了緩存裡。在4G記憶體的筆記本裡,處理速度能達到10W條/秒。
三:為什麼要用讀寫雙緩沖隊列
在操作第二步的時候,業務程式寫入的100W條資料,絕大多數還在緩存對列裡,還沒有持久化到硬碟上,可以通過如下代碼監視讀寫緩存和已持久化到硬碟上的資料。
Thread watchThread = new Thread(new ParameterizedThreadStart((para) =>
{
DateTime startDT = DateTime.Now;
while (NLogger.totalCount < 1000000)
{
DateTime sectionDt = DateTime.Now;
TimeSpan ts = sectionDt - startDT;
Console.WriteLine(string.Format("已用時{0}秒 已寫入{1}條 寫緩存{2}條 讀緩存{3}條", (int)ts.TotalSeconds, NLogger.totalCount, NLogger.writeQueue.Count, NLogger.readQueue.Count));
Thread.Sleep(1000);
}
}));
watchThread.IsBackground = true;
watchThread.Start("");
可以看到在第10秒的時候,100W條資料已經被業務程式全部處理完成。其中有近83W條資料在緩存裡,有13W條資料已經刷到了硬碟裡,因是為按秒監控,有4W條資料的誤差。持續了50秒,才把100W條資料全部刷到硬碟裡。
大量的日志存儲在緩沖隊列裡,在重新整理硬碟的時候,不可能一條一條的重新整理資料,雖然現在的固态硬碟已經在市場上流行了很多年,還是沒有完全普及,在很多計算機上IO還是瓶頸。如果能做到一次能重新整理多條資料,就會提高刷盤的速度。每次刷多少資料到硬碟才能達到最優值?本機是設定的64KB,不同的計算機可能這個值有所不同。
具體的實作代碼如下:
while (true)
{
if (readQueue.Count > 0)
{
string[] qItem = readQueue.Dequeue() as string[];
totalCount = totalCount + 1;
string[] tempItem = tempQueue.Find(d => d[0] == qItem[0] && d[1] == qItem[1]);
if (tempItem == null)
{
tempQueue.Add(qItem);
}
else
{
tempItem[2] = string.Concat(tempItem[2], Environment.NewLine, qItem[2]);
if (tempItem[2].Length > 64 * 1024) //(1 * 1024 * 1024 = 1M);
{
break;
}
}
}
else
{
break;
}
}
在多線程的世界裡, AutoResetEvent, ManualResetEvent這兩個類是十分重要的。它們的差別,網上是到處都有介紹的,本篇部落格就隻做一個入門級的介紹。
這兩個類稱為信号量類,主要包括如下三個方法:
WaitOne()
Set()
Reset()
如果把線程比作水管,WaitOne() 就是水閥,Set()就是通知打開水閥,Reset()就是通知關閉水閥。介紹信号量的部落格都喜歡舉這個例子,照葫蘆畫瓢引用了這個例子。
在日志類裡開啟一個刷盤的線程,在閑時是不運作,也不會占用很多的系統資源,因為WaitOne()水閥狀态是關閉着的。一旦别的線程往緩沖隊列裡寫日志資料,就用Set()信号量通知打開水閥,日志刷盤完畢後,用Reset()信号量通知把水閥關起來。
這樣就用信号量的原理實作了即時刷盤的機制。
六:RollingFile日志
在特别的場景下,比如即時消息系統,WEB應用系統,日志量都很大,一天可以達到G級别量的日志,一般情況下,記錄本檔案超過10M,打開速度就比較慢,而且不便于定位和檢視。這時就需要對日志檔案進行分割,分割日志檔案常用的手法一般從兩個次元進行,一個是按時間次元,一個是按日志的體積。NLogger采用了時間次元和日志次元疊加的方法來進行日志的分割。
分割日志是一件很容易的事情,難的是對新的日志檔案的命名,比如現在的日志檔案名是test_20170212(7).log,怎麼能計算出下一個日志檔案應該是test_20170212(8).log呢?用正規表達式的方式,先比對出檔案名的數字,再計算出下一個檔案的名字。這兒的正則式就有含量了,抗幹擾性要強,容錯性要高,才能比對出更精準的數字。
并不是每個程式的日志資訊都存儲在自身程式目錄裡,有可能定義到其它盤符,或者其它伺服器上的共享目錄,支援日志存儲位置自定義是有必要的。
不同的應用場景,為了區分日志的分類,有必要在日志檔案名前加一個字首,很幸運NLoger支援了這一功能。
八:與标杆日志元件log4net一試高低
Log4net的普及度是很高的,這兒不做詳細介紹如何配置使用了。把測試的代碼貼出來,熟手一看就明白了。
這兒做一個Log4net的标配檔案:
<configuration>
<configSections>
<section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler,log4net"/>
</configSections>
<log4net>
<appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender" >
<Encoding value="UTF-8" />
<file value="Logs/" />
<!--記錄日志寫入檔案時,不鎖定文本檔案,防止多線程時不能寫Log,官方說線程非安全-->
<lockingModel type="log4net.Appender.FileAppender+MinimalLock"/>
<!--按照何種方式産生多個日志檔案(日期[Date],檔案大小[Size],混合[Composite])-->
<rollingStyle value="Composite" />
<!--按照日期格式輸出檔案路徑-->
<datePattern value="yyyyMMdd'.txt'"/>
<!--是否隻寫到一個檔案中-->
<staticLogFileName value="false"/>
<!--每個檔案的大小-->
<maximumFileSize value="1MB"/>
<!--最多産生的日志檔案數,超過則隻保留最新的n個。設定值value="-1"為不限檔案數-->
<maxSizeRollBackups value="100"/>
<!--程式啟動後,是否追加到檔案-->
<appendToFile value="true" />
<!--日志緩存大小-->
<bufferSize value="128" />
<!--日志格式-->
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date [%thread] %message %newline" />
</layout>
</appender>
<root>
<appender-ref ref="RollingFileAppender" />
<level value="DEBUG" />
</root>
</log4net>
</configuration>
為了測試的公平性,測試代碼的邏輯與測試資料和NLogger都是相同的:
for (int count = 0; count < 10; count++)
{
Thread writeThread = new Thread(new ParameterizedThreadStart((para) =>
{
log4net.ILog log = log4net.LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType);
Console.WriteLine(string.Format("開啟線程{0}", para));
Stopwatch sw = new Stopwatch();
sw.Start();
for (int i = 0; i < 100000; i++)
{
log.Info(string.Format("日志測試資料,序号:{0}", i.ToString()));
}
sw.Stop();
Console.WriteLine(string.Format("線程{0}寫入日志結束,共用時{1}毫秒", para, sw.ElapsedMilliseconds));
}));
writeThread.IsBackground = true;
writeThread.Start(count);
}
log4net寫日志,測試開啟10個線程,共寫100W條資料到硬碟,吃了個午飯回來還沒有執行結束。NLogger 10秒刷100W條資料到緩存,50秒刷100W條資料到硬碟,這樣的對比,意義已經不大了。
測試源碼下載下傳(包括NLogger .net2.0版源碼)
想了解更多,請翻閱以前的部落格,在網頁右下角點選推薦。
下篇将NLogger .net4.0版貼出來,性能是優于.net2.0版的。