在面對系統異常的時候，擁有Log是相當重要的，它可以幫助我們了解發生異常時的系統狀況是如何，而在.Net中可以使用的Log Library也相當的多元，例如常見的log4net、Enterprise Library Logging Application Block等等，每一個都有自己的優點和特性，大家可以依照自己的使用習慣來選擇，而今天要向大家介紹的是Nlog這套Library，並且將示範如何使用Autofac整合進系統之中，以及其他相關的應用。
※安裝Nlog
由於我們希望可以直接Autofac來管理Nlog的Instance，所以我們選擇使用Utlity.Logging這套Library，它提供了Nlog與Autofac的整合，並且也提供的Logger的介面讓我們可以降低Logger與程式碼的耦合性。
在網站使用Nuget安裝Utility.Logging.Nlog.Autofac
在AutofacConfig中新增註冊NlogLoggerAutofacModule，如此一來Autofac就會自動注入Logger的實體
builder.RegisterModule(new NLogLoggerAutofacModule());
修改我們的ProductController，增加ILogger，用來寫Log，並在Action中寫入一條Log
public class ProductController : JsonNetController
{
public IProductService ProductService { get; set; }
public ILogger Logger { get; set; }
public ProductController(IProductService productService, ILogger logger)
{
this.ProductService = productService;
this.Logger = logger;
}
[AuthorizeByToken(Roles = "Administrator")]
public ActionResult GetProductByCategory(int id)
{
this.Logger.Debug("Execute GetProductByCategory - {0}", id);
var result = this.ProductService.GetProductByCategoryId(id);
return Json(result, JsonRequestBehavior.AllowGet);
}
}
其實到這邊Nlog已經安裝完了，但執行後卻發現沒有產生任何的Log，這是由於我們還沒有設定Nlog使用何種方式寫Log
※設定Nlog的Config
我們可以透過Nuget來直接取得Nlog Config的範本，並且還提供Intellisence的支援！
在網站使用Nuget安裝Nlog.Configuration
我們會看到網站下出現Nlog.config的樣板，target代表輸出使用者方法(例如:file、database)，rule代表logger的設定 (在這邊logger名稱預設呼叫class的名稱)
我們在config的targets中增加一個target，代表將log寫到檔案之中
<targets>
<target xsi:type="File" name="f" fileName="${basedir}/App_Data/Logs/${shortdate}.log" layout="${longdate} ${uppercase:${level}} ${message}" />
</targets>
接下來設定rule，指定哪些logger要套用到哪些target，在這邊我們指定所有的logger都使用寫到檔案的target，並且包含所有level的訊息
<rules>
<logger name="*" minlevel="Debug" writeTo="f" />
</rules>
執行查詢，我們可以看到真的產生Log
※擴充Nlog
在有了Log之後，Log的分類與內容就是很重要的課題了，由於當網站的量開始增加時，若是沒有妥善的分類，就會產生Log檔案難以閱讀的問題，因此我們希望Log檔案在產生的時候就可以依據Controller和Action分開資料夾，更甚至可以按照每一個Request來產生獨立的Log檔案，這麼一來，每一個使用者查詢的歷程都可以很輕鬆的在獨立的Log檔案中找到。
擴充Controller和Action的Layout Renderer，在Utility的Extensions新增ControllerLayoutRenderer和ActionLayoutRenderer
[LayoutRenderer("aspnetmvc-controller")]
public class ControllerLayoutRenderer : LayoutRenderer
{
protected override void Append(StringBuilder builder, NLog.LogEventInfo logEvent)
{
var controllerName = string.Empty;
if (HttpContext.Current != null)
{
controllerName = HttpContext.Current.Request.RequestContext.RouteData.Values["controller"].ToString();
}
builder.Append(controllerName);
}
}
[LayoutRenderer("aspnetmvc-action")]
public class ActionLayoutRenderer : LayoutRenderer
{
protected override void Append(StringBuilder builder, NLog.LogEventInfo logEvent)
{
var actionName = string.Empty;
if (HttpContext.Current != null)
{
actionName = HttpContext.Current.Request.RequestContext.RouteData.Values["action"].ToString();
}
builder.Append(actionName);
}
}
在網站使用Nuget安裝Nlog.Extend (為了使用aspnet-sessionid)
在網站新增NlogConfig，註冊我們擴充的LayoutRenderer
public class NLogConfig
{
public static void Initialize()
{
ConfigurationItemFactory.Default.LayoutRenderers.RegisterDefinition("aspnetmvc-controller", typeof(ControllerLayoutRenderer));
ConfigurationItemFactory.Default.LayoutRenderers.RegisterDefinition("aspnetmvc-action", typeof(ActionLayoutRenderer));
}
}
在Global.asax新增啟動NlogConfig
NLogConfig.Initialize();
修改Nlog.config，我們希望依照Controller和Action區分資料夾，並可以每一個Request記錄一個Log檔，因此我們使用session id作為檔名，由於session id需要使用Nlog.Extend，我們先在Config中註冊Nlog.Extend的使用
<extensions>
<add assembly="NLog.Extended"/>
</extensions>
修改log檔案的寫入位置
<target xsi:type="File" name="file" fileName="${basedir}/App_Data/Logs/${shortdate}/${aspnetmvc-controller}/${aspnetmvc-action}/${aspnetmvc-action}-${aspnet-sessionid}.txt"
layout="${longdate} ${uppercase:${level}} ${message}" />
重新查詢，我們可以看到Log檔案整齊的被分類了，而且每個Log檔案代表一個Request的歷程，方便我們找出發生問題的原因
※記錄Api每次的輸出輸入資訊
除了記錄了Log的資訊之外，我們還希望可以針對Api每次傳進來跟回傳的內容做更詳細的紀錄，甚至存在資料庫中以供分析追蹤，我們可以透過NLog的靈活特性來簡單時現這個機制。
新增LoggingDB，方法可以參考之前的文章
新增Table，用來儲存Request和Response的資料
USE [LoggingDB]
GO
/****** Object: Table [dbo].[ApiRequest] Script Date: 2013/10/16 下午 02:54:21 ******/
SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO
SET ANSI_PADDING ON
GO
CREATE TABLE [dbo].[ApiRequest](
[Id] [int] IDENTITY(1,1) NOT NULL,
[Controller] [nvarchar](50) NOT NULL,
[Action] [nvarchar](50) NOT NULL,
[Url] [varchar](300) NOT NULL,
[SessionId] [nvarchar](50) NOT NULL,
[IP] [varchar](20) NOT NULL,
[RequestMethod] [varchar](10) NOT NULL,
[Level] [varchar](10) NOT NULL,
[LoggerName] [nvarchar](100) NOT NULL,
[Message] [nvarchar](4000) NOT NULL,
[CreatedAt] [datetime] NOT NULL,
[CreatedBy] [nvarchar](100) NOT NULL,
CONSTRAINT [PK_ApiRequest] PRIMARY KEY CLUSTERED
(
[Id] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]
) ON [PRIMARY]
GO
SET ANSI_PADDING OFF
GO
ALTER TABLE [dbo].[ApiRequest] ADD CONSTRAINT [DF_ApiRequest_CreatedAt] DEFAULT (getdate()) FOR [CreatedAt]
GO
在Utility的Extensions新增LogRequestAttribute，我們透過ActionFilter的方式，在每次Action執行前後記錄資料
public class LogRequestAttribute : ActionFilterAttribute
{
public ILogger Logger { get; set; }
public LogRequestAttribute(ILogger logger)
{
this.Logger = logger;
}
public override void OnActionExecuting(ActionExecutingContext filterContext)
{
var formData = JsonConvert.SerializeObject(filterContext.ActionParameters);
this.Logger.Trace(string.Format("OnActionExcuting | {0} ", formData));
}
public override void OnActionExecuted(ActionExecutedContext filterContext)
{
var result = string.Empty;
if (filterContext.Result is JsonResult)
{
result = JsonConvert.SerializeObject((filterContext.Result as JsonResult).Data);
}
if (filterContext.Exception != null)
{
result = filterContext.Exception.Message;
}
this.Logger.Trace(string.Format("OnActionExcuted | {0} ", result));
}
}
在網站的web.config的autofac區段註冊Attribute
<components>
<component type="ApiSample.Utility.Extensions.Nlog.LogRequestAttribute, ApiSample.Utility.Extensions"
service="ApiSample.Utility.Extensions.Nlog.LogRequestAttribute, ApiSample.Utility.Extensions" />
</components>
在FilterConfig，註冊所有的Action都會經過此actionFilter，用來記錄整個Api的Request/Response
filters.Add(DependencyResolver.Current.GetService<LogRequestAttribute>());
在Nlog.config新增寫入資料庫的Target，以及Sql語法
<target name="database" type="Database">
<dbprovider>mssql</dbprovider>
<connectionstring>Data Source=(LocalDb)\ApiSample;Initial Catalog=LoggingDB;Integrated Secu rity=S SPI;AttachDBFilename=C:\LocalDB\ApiSample\LoggingDB.mdf</connectionstring>
<commandText>
insert into ApiRequest(Controller,Action,Url,SessionId,IP,RequestMethod,Level,LoggerName,Message,CreatedBy) values (@Co ntroller, @Action, @Url, @SessionId, @IP, @RequestMethod, @Level, @LoggerName, @Message, @CreatedBy);
</commandText>
<parameter name="@Controller" layout="${aspnetmvc-controller}" />
<parameter name="@Action" layout="${aspnetmvc-action}" />
<parameter name="@Url" layout="${aspnet-request:serverVariable=url}" />
<parameter name="@SessionId" layout="${aspnet-sessionid}" />
<parameter name="@IP" layout="${aspnet-request:serverVariable=remote_host}" />
<parameter name="@RequestMethod" layout="${aspnet-request:serverVariable=request_method}" />
<parameter name="@Level" layout="${level}" />
<parameter name="@LoggerName" layout="${logger}" />
<parameter name="@Message" layout="${message}" />
<parameter name="@CreatedBy" layout="NLog" />
</target>
在前面有提過，所有Logger的名稱預設都是目前class的名稱，因此，我們只將LogRequestAttribute裡面Logger所記錄的東西寫到資料庫
<logger name="ApiSample.Utility.Extensions.Nlog.LogRequestAttribute" level="Trace" writeTo="database" />
重新查詢程式，發現Log已經寫到資料庫之中
如此一來，我們可以透過資料庫清楚的得知所有Request/Response的資料，並且還可以透過sessionid來追查該Request的詳細歷程
※本日小結
透過Log的靈活彈性，我們可以很輕鬆的達成我們的目標，然後在持續的營運網站上面，適度的增加Log也是很重要的，如果使用了大量而且無意義的Log檔只會增加日後管理硬碟空間上的成本，所以如何取捨也是一們很重要的課題，關於今天的內容，歡迎大家一起討論 ^_^
iThome鐵人賽
看影片追技術