性能秒殺log4net的NLogger日誌組件(附測試代碼與NLogger源碼)

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版的。