0

NLog是我們開發團隊的奧林匹克指定Log元件，但經驗裡遇過不少次沒有寫Log檔的狀況，而NLog為了避免寫Log過程出錯導致主程序中斷，預設不會拋出錯誤訊息，這讓NLog茶包特別難找。過去較常見問題是對Log資料夾缺少寫入權限（尤其是IIS 7.5+會用IIS APPPOOL\XXXX虛擬帳號，需要額外開權限），補設權限後就OK，對NLog問題如何除錯也未多深究。不料前幾天踢到鐵板，足足卡了一小時找出原因（代表以前是假會，只要不是權限問題就卡關，嗚～），不過因此學會NLog異常排除技巧是意外收獲。

NLog預設會忽略所有發生的錯誤（包含NLog.config壞掉都假裝沒事）以免干擾主程式執行，當需要偵錯時，NLog.config有個開關：<nlog throwExceptions="true" />，開啟後便知NLog為什麼沒成功寫入Log。

來個測試，故意移除Log資料夾寫入權限，並加上throwExceptions="true"，錯誤訊息與爆炸程式行數一目瞭然：

除了設定NLog在出錯時直接拋出錯誤，還有另一種有效蒐集錯誤訊息的做法：<nlog internalLogLevel="Debug" internalLogFile="c:\temp\nlog-internal.log">，透過internalLogLevel及internalLogFile開啟NLog的內部Log，從中也可找出NLog無法寫入Log的原因（如下圖）。與throwExceptions="true"有以下不同：

  1. internalLogFile錯誤訊息的StackTracce資訊從NLog元件內部開始（在下例為NLog.Tragets.Target.Write），追不到logger.Debug()等寫入Log的程式來源。
  2. 若internalLogFile路徑遇上無權寫入，一樣暴斃驗無傷。
  3. internalLogFile不只可以記錯誤訊息，當internalLogLevel設成Debug、Trace等模式，還能看到更多NLog運作資訊。

同場加映一則小技巧－如何快速找出Target f的檔案路徑？結合先前介紹過的取得NLog檔案路徑以及在IIS主機現場撰寫測試ASPX偵錯，以下程式顯示LoggerName為"AAA"時的Log路徑，並試寫一個Debug Log，第一行NLog.LogManager.ThrowExceptions = true 可取代 <nlog throwExceptions="true">設定，在NLog出錯時顯示錯誤訊息。透過此一測試可以確認Log檔案位置以及寫入權限。

<%@ Page Language="C#" %> 
<% 
NLog.LogManager.ThrowExceptions = true; 
Response.Write( 
(NLog.LogManager.Configuration.FindTargetByName("f") as NLog.Targets.FileTarget).FileName 
.Render(new NLog.LogEventInfo() { TimeStamp = DateTime.Now, LoggerName = "AAA" }) 
); 
NLog.LogManager.GetLogger("AAA").Debug("TEST"); 
NLog.LogManager.Flush(); 
%>

還有一點，NLog.config在修改後，需要重啟Web Application才會生效，有個<nlog autoReload="true">可在NLog.config修改時自動載入，可在不中斷ASP.NET或Windows程序調整NLog設定。

【結論】

  1. NLog預設會壓抑所有NLog錯誤以免中斷主要程式邏輯，設定<nlog throwExceptions="true">可顯示NLog錯誤。
    提醒：問題排除後建議改回false，或用在測試程式中以NLog.LogManager.ThrowExceptions=true替代。
  2. 遇到NLog問題時，可寫一個迷你NLogTester.aspx檢查路徑及寫入權限。（範例請見文章）
  3. <nlog autoReload="true">可設定NLog.config修改後自動更新設定，省去重啟程序的困擾。

【延伸閱讀】

  1. Configuration file · NLog-NLog Wiki · GitHub
  2. Logging Troubleshooting · NLog-NLog Wiki · GitHub

【後記】

我這次遇到的狀況是程式換版，將已平測一段時間的新版資料夾取名取代舊版（包含NLog.config），後來想到要沿用原本NLog.config指定的Log路徑，再把舊版的NLog.config覆寫回去，從此再也沒看到有Log寫入。該Log路徑在換版前原本就運作良好，不該是權限問題，讓過去只會處理NLog DLL版本衝突跟Log目錄權限茶包的我黔驢技窮，瞎試半天無解，爬文學會開啟throwExceptions才水落石出：

Exception Details: System.IO.FileNotFoundException: Could not load file or assembly 'NLog.Targets.Syslog' or one of its dependencies. The system cannot find the file specified.

舊版的NLog.config設定了Syslog Target，如下例：

<?xml version="1.0" encoding="utf-8" ?> 
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd" 
      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"> 
  <extensions> 
    <add assembly="NLog.Targets.Syslog" /> 
  </extensions>    
  <targets> 
    <target xsi:type="File" name="f" fileName="D:/Log/${logger}/${shortdate}.log" 
            layout="${longdate} ${uppercase:${level}} ${message}" encoding="utf-8"/> 
    <target name="syslog" type="Syslog" syslogserver="syslog-server-ip" 
            port="514" facility="Local7" 
            sender="BLAH.UAT" layout="${longdate} ${uppercase:${level}} ${message}"/>            
  </targets> 
  <rules> 
    <logger name="*" minlevel="Trace" writeTo="f,syslog" /> 
  </rules> 
</nlog>

extensions引用了NLog.Targets.Syslog，舊版bin下有NLog.Targets.Syslog.dll，忘了複製到新版bin目錄導致錯誤，補上後問題排除。


Comments

Be the first to post a comment

Post a comment