愛流浪的小風

技術隨手寫

使用Asp.Net MVC打造Web Api (17) - 使用Nlog記錄系統訊息

| Comments

在面對系統異常的時候,擁有Log是相當重要的,它可以幫助我們了解發生異常時的系統狀況是如何,而在.Net中可以使用的Log Library也相當的多元,例如常見的log4net、Enterprise Library Logging Application Block等等,每一個都有自己的優點和特性,大家可以依照自己的使用習慣來選擇,而今天要向大家介紹的是Nlog這套Library,並且將示範如何使用Autofac整合進系統之中,以及其他相關的應用。

安裝Nlog

由於我們希望可以直接Autofac來管理Nlog的Instance,所以我們選擇使用Utlity.Logging這套Library,它提供了Nlog與Autofac的整合,並且也提供的Logger的介面讓我們可以降低Logger與程式碼的耦合性。

  1. 在網站使用Nuget安裝Utility.Logging.Nlog.Autofac

  2. 在AutofacConfig中新增註冊NlogLoggerAutofacModule,如此一來Autofac就會自動注入Logger的實體

    builder.RegisterModule(new NLogLoggerAutofacModule());
    
  3. 修改我們的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);
        }                
    }
    
  4. 其實到這邊Nlog已經安裝完了,但執行後卻發現沒有產生任何的Log,這是由於我們還沒有設定Nlog使用何種方式寫Log

設定Nlog的Config

我們可以透過Nuget來直接取得Nlog Config的範本,並且還提供Intellisence的支援!

  1. 在網站使用Nuget安裝Nlog.Configuration

  2. 我們會看到網站下出現Nlog.config的樣板,target代表輸出使用者方法(例如:file、database),rule代表logger的設定 (在這邊logger名稱預設呼叫class的名稱)

  3. 我們在config的targets中增加一個target,代表將log寫到檔案之中

    <targets>          
        <target xsi:type="File" name="f" fileName="${basedir}/App_Data/Logs/${shortdate}.log" layout="${longdate} ${uppercase:${level}} ${message}" />    
    </targets>
    
  4. 接下來設定rule,指定哪些logger要套用到哪些target,在這邊我們指定所有的logger都使用寫到檔案的target,並且包含所有level的訊息

    <rules>    
        <logger name="*" minlevel="Debug" writeTo="f" />    
    </rules>
    
  5. 執行查詢,我們可以看到真的產生Log

擴充Nlog

在有了Log之後,Log的分類與內容就是很重要的課題了,由於當網站的量開始增加時,若是沒有妥善的分類,就會產生Log檔案難以閱讀的問題,因此我們希望Log檔案在產生的時候就可以依據Controller和Action分開資料夾,更甚至可以按照每一個Request來產生獨立的Log檔案,這麼一來,每一個使用者查詢的歷程都可以很輕鬆的在獨立的Log檔案中找到。

  1. 擴充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);
        }
    }
    
  2. 在網站使用Nuget安裝Nlog.Extend (為了使用aspnet-sessionid)

  3. 在網站新增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));
        }
    }
    
  4. 在Global.asax新增啟動NlogConfig

    NLogConfig.Initialize();
    
  5. 修改Nlog.config,我們希望依照Controller和Action區分資料夾,並可以每一個Request記錄一個Log檔,因此我們使用session id作為檔名,由於session id需要使用Nlog.Extend,我們先在Config中註冊Nlog.Extend的使用

    <extensions>
        <add assembly="NLog.Extended"/>
    </extensions>
    
  6. 修改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}" />
    
  7. 重新查詢,我們可以看到Log檔案整齊的被分類了,而且每個Log檔案代表一個Request的歷程,方便我們找出發生問題的原因

記錄Api每次的輸出輸入資訊

除了記錄了Log的資訊之外,我們還希望可以針對Api每次傳進來跟回傳的內容做更詳細的紀錄,甚至存在資料庫中以供分析追蹤,我們可以透過NLog的靈活特性來簡單時現這個機制。

  1. 新增LoggingDB,方法可以參考之前的文章

  2. 新增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
    
  3. 在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));
        }
    }        
    
  4. 在網站的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>        
    
  5. 在FilterConfig,註冊所有的Action都會經過此actionFilter,用來記錄整個Api的Request/Response

    filters.Add(DependencyResolver.Current.GetService<LogRequestAttribute>());    
    
  6. 在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>    
    
  7. 在前面有提過,所有Logger的名稱預設都是目前class的名稱,因此,我們只將LogRequestAttribute裡面Logger所記錄的東西寫到資料庫

    <logger name="ApiSample.Utility.Extensions.Nlog.LogRequestAttribute" level="Trace" writeTo="database" />  
    
  8. 重新查詢程式,發現Log已經寫到資料庫之中

如此一來,我們可以透過資料庫清楚的得知所有Request/Response的資料,並且還可以透過sessionid來追查該Request的詳細歷程

本日小結

透過Log的靈活彈性,我們可以很輕鬆的達成我們的目標,然後在持續的營運網站上面,適度的增加Log也是很重要的,如果使用了大量而且無意義的Log檔只會增加日後管理硬碟空間上的成本,所以如何取捨也是一們很重要的課題,關於今天的內容,歡迎大家一起討論 ^_^

Comments

comments powered by Disqus