[筆記][WebAPI] Message Handler 初體驗-搭配 NLog 記錄所有 WebAPI 的 Request 與 Response

2014-08-04

10691
0
(.NET)Web API
2017-04-15

WebAPI 的應用中，有一個 Message Handler ，可以讓我們在不改 Web API 的情況下，透過 Message Handler 來處理一些 WebAPI 共同要處理的項目。讓這些處理的事情，與 WebAPI 要處理的事情有很好的權責分離，彼此只需要專注處理自己要做的，又能夠好好的配合。

小喵剛好有個需求，想要記錄某個專案中，WebAPI的進出內容，一來未來當作分析依據，二來保留下來有爭議時可以當作依據。借由NLog來記錄，因NLog簡單易用，對於效能的影響很小，剛好將這兩個技術一起搭配來做個練習。怎麼做，讓我們繼續看下去~

緣起

WebAPI 的應用中，有一個 Message Handler ，可以讓我們在不改 Web API 的情況下，透過 Message Handler 來處理一些 WebAPI 共同要處理的項目。讓這些處理的事情，與 WebAPI 要處理的事情有很好的權責分離，彼此只需要專注處理自己要做的，又能夠好好的配合。

小喵剛好有個需求，想要記錄某個專案中，WebAPI的進出內容，一來未來當作分析依據，二來保留下來有爭議時可以當作依據。借由NLog來記錄，因NLog簡單易用，對於效能的影響很小，剛好將這兩個技術一起搭配來做個練習。怎麼做，讓我們繼續看下去~

本篇重點會放在如何使用，至於概念與教學，會提供相關參考文章的網址，以供參考。

Message Handler簡介

Message Handler 的生產線(PipeLine)特性，可以讓我們撰寫數個 Message Handler 串在一個生產線，就像在進出WebAPI這個大工廠前後，可以有兩條生產線，中間設定數個工作區，每個工作區分別執行各自要關注的事情。

(以下圖片來自官方網站http://www.asp.net/web-api/overview/working-with-http/http-message-handlers)

Huan-Lin老師的介紹文章：http://huan-lin.blogspot.com/2013/08/nlog-configuration-example.html

KKBruce的介紹文：http://blog.kkbruce.net/2012/05/aspnet-web-api-8-http-http-message.html#.U97cv_mSxps

NLog簡介：

NLog是個用來做Log的好物，透過簡單的設定，就能夠用來文字、資料庫、Windows 事件 Log、Text Console、甚至直接Log到遠方的Server(透過TCP/IP)、EMail通知等。

使用上，可以根據不同的情況(等級)做出不同的Log

Trace - Very detailed log messages, potentially of a high frequency and volume
Debug -Less detailed and/or less frequent debugging messages
Info - Informational messages
Warn - Warnings which don't appear to the user of the application
Error - Error messages
Fatal - Fatal error messages. After a fatal error, the application usually terminates.

相關詳細的說明，小喵不在這篇裡面聊這部分，有興趣的可以參考以下的資源

CodeProject：http://www.codeproject.com/Articles/10631/Introduction-to-NLog
保哥：http://blog.miniasp.com/post/2010/07/18/Useful-Library-NLog-Advanced-NET-Logging.aspx
官方：http://nlog-project.org/

使用上感覺對於效能的影響不大，功能卻很強大。這次的練習就以記錄為文字檔的方式來處理。

到此，簡單的介紹用到的兩個東西：Message Handler 與 NLog，接著，就是實站的部分，如何撰寫來達到想要的目的。

NLog

首先是NLog的一些設定

取得NLog

NLog可以透過NuGet來取得，請取得以下的這幾個

NLog
NLog Schema for Intellisense
NLog Configuration

設定NLog Configuration

安裝完上面所列出來的項目後，就可以在專案中找到【NLog.config】。他是一個xml格式的設定檔，設定哪些等級要Log，以及Log要記錄的格式與內容。請參考如下：

<?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">

  <!-- 
  See http://nlog-project.org/wiki/Configuration_file 
  for information on customizing logging rules and outputs.
   -->
  <targets>
    <!-- add your targets here -->
    <!-- 要儲存Log的方式記錄在此 -->
	
    <target name="file" xsi:type="File"
            fileName="${basedir}/App_Data/Logs/${shortdate}/${logger}.txt"
            layout="${longdate} | ${level:uppercase=true} | TID:${threadid} | ${message} ${newline}" />
    <target name="log" xsi:type="File"
            fileName="${basedir}/App_Data/Logs/${shortdate}/${logger}.txt"
            layout="${longdate} | ${level:uppercase=true} | TID:${threadid} | ${message} ${newline}" />
    <target name="eventlog" xsi:type="EventLog"
        source="Lab_Of_NLog" log="Application"
        layout="${date}: ${message} ${stacktrace}" />

  </targets>

  <rules>
    <!-- add your logging rules here -->
	
	<!--
		這邊設定什麼樣的等級要做Log,而writeTo對照上方的Target，搭配看要用什麼方式記錄
		隨時可以註解掉，來關閉/打開相關的Log，不影響程式
	-->
	
    <logger name="*" levels="Info" writeTo="log" />
	<!--
    <logger name="*" levels="Trace" writeTo="file" />
    <logger name="*" level="Fatal" writeTo="eventlog" />
    -->

  </rules>
</nlog>

設定上，小喵特別讓Log寫到專案的App_Data這個特殊的資料夾，由於ASP.NET會特別針對這個資料夾的資料進行保護，也方便移行時可以自動產生，實際上大家可以依據自己的需求來修改。

設定的部分就到此，一個檔案而已，很簡單。接著，就是 Message Handler 登場。

Message Handler

小喵的需求是透過 Message Handler ，在 Request 與 Response 的時候，將內容(包含Header, Content)給記錄下來，這裡需要處理三個部分

記錄Requesst, Response內容的LogDao
Message Handler呼叫記錄內容dao
將寫好的Message Handler 透過 Global.asax 加入

以下就分別來看每個部分如何撰寫：

撰寫LogDao的部分

在Models中，新增一個類別【MessageHandlerLogDao】，撰寫程式碼如下：

Imports System.Net.Http

Public Class MessageHandlerLogDao
    '宣告NLog的Logger
    Private logger As NLog.Logger = NLog.LogManager.GetCurrentClassLogger()

    ''' <summary>
    ''' 儲存Log
    ''' </summary>
    ''' <param name="request">Request(HttpRequestMessage的內容)</param>
    ''' <param name="response">Response(HttpResponseMessage的內容)</param>
    ''' <remarks></remarks>
    Public Sub SaveLog(ByVal request As HttpRequestMessage, ByVal response As HttpResponseMessage)
        Dim caller As Object = System.Reflection.MethodBase.GetCurrentMethod().Name

        Dim spTxt1 As String = "-----------------------------------------------"
        Dim spTxt2 As String = "==============================================="
        Dim requestContent As String = request.Content.ReadAsStringAsync.Result.ToString
        Dim responseContent As String = response.Content.ReadAsStringAsync.Result.ToString

        logger.Info(vbCrLf & "Request:" & vbCrLf & request.ToString & vbCrLf & "Request Content:" & vbCrLf & requestContent & vbCrLf & spTxt1 & vbCrLf & "Response:" & vbCrLf & response.ToString & vbCrLf & "Response Content : " & vbCrLf & responseContent & vbCrLf & spTxt2 & vbCrLf)


    End Sub
End Class

透過NLog的Info命令，將進出的 Request 與 Response 寫入，Message Handler會以非同步的方式運作，所以在取得Response.Content的部分，透過ReadAsStringAsync.Result來取得最後真正的Response內容。

撰寫 Message Handler

接著，就來撰寫Message Handler的部分。我們繼續在Models裡面，新增一個類別【LogOverrideHandler】來當作 Message Handler。這類別我們要繼承【DelegatingHandler】，並且改寫【SendAsync】的方法，來加入我們要做的事情，相關程式碼如下：

Imports System.Net.Http

Public Class LogOverrideHandler
    Inherits DelegatingHandler

    Protected Overrides Async Function SendAsync(request As HttpRequestMessage, cancellationToken As Threading.CancellationToken) As Threading.Tasks.Task(Of HttpResponseMessage)
        '這裡可以針對Request進行額外的處理，這裡加一個Header當作範例。
        request.Headers.Add("MyMessageHandlerHead", "SendMessageHandler-" & Format(Now, "yyyyMMddHHmmss"))

        '透過非同步方式運作，這裡來承接回傳時的response內容
        Dim response = Await MyBase.SendAsync(request, cancellationToken)

        '呼叫LogDao來存Log
        Dim LogDao As New MessageHandlerLogDao
        LogDao.SaveLog(request, response)

        '把response繼續往前傳
        Return response

    End Function
End Class

將 Message Handler 透過 Global.asax 掛上

最後，我們要把我們寫好的 Message Handler 掛上，讓他起作用，這時我們要打開 Global.asax 這個檔案改寫

Imports System.Web.Http
Imports System.Web.Optimization

Public Class WebApiApplication
    Inherits System.Web.HttpApplication

    ''' <summary>
    ''' 掛載Message Handler
    ''' </summary>
    ''' <param name="config"></param>
    ''' <remarks></remarks>
    Shared Sub Configure(config As HttpConfiguration)
        '這裡可以設定要掛載多組Message Handler
        config.MessageHandlers.Add(New LogOverrideHandler())
        'config.MessageHandlers.Add(New Log2OverrideHandler())
    End Sub

    Protected Sub Application_Start()
        '在Application_Start事件，呼叫寫的Sub掛上
        Configure(GlobalConfiguration.Configuration)

        AreaRegistration.RegisterAllAreas()
        GlobalConfiguration.Configure(AddressOf WebApiConfig.Register)
        FilterConfig.RegisterGlobalFilters(GlobalFilters.Filters)
        RouteConfig.RegisterRoutes(RouteTable.Routes)
        BundleConfig.RegisterBundles(BundleTable.Bundles)
    End Sub
End Class

記錄的結果

就這樣，就可以讓 Message Handler 開始運作，針對專案中的所有 Web API，記錄下來他們的進(request)與出(response)的相關資訊，以備未來查驗。

我們以北風的Products來做範例，記錄的結果就像以下這樣：

2014-08-04 19:03:24.2200 | INFO | TID:8 | 
Request:
Method: GET, RequestUri: 'http://localhost:39553/api/product/1', Version: 1.1, Content: System.Web.Http.WebHost.HttpControllerHandler+LazyStreamContent, Headers:
{
  Connection: keep-alive
  Accept: text/html
  Accept: application/xhtml+xml
  Accept: application/xml; q=0.9
  Accept: image/webp
  Accept: */*; q=0.8
  Accept-Encoding: gzip
  Accept-Encoding: deflate
  Accept-Encoding: sdch
  Accept-Language: zh-TW
  Accept-Language: zh; q=0.8
  Accept-Language: en-US; q=0.6
  Accept-Language: en; q=0.4
  Host: localhost:39553
  User-Agent: Mozilla/5.0
  User-Agent: (Windows NT 6.1; WOW64)
  User-Agent: AppleWebKit/537.36
  User-Agent: (KHTML, like Gecko)
  User-Agent: Chrome/36.0.1985.125
  User-Agent: Safari/537.36
  MyMessageHandlerHead: SendMessageHandler-20140804190323
  Content-Length: 0
}
Request Content:

-----------------------------------------------
Response:
StatusCode: 200, ReasonPhrase: 'OK', Version: 1.1, Content: System.Net.Http.ObjectContent`1[[MessageHandlerDemo01.ProductInfo, MessageHandlerDemo01, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null]], Headers:
{
  Content-Type: application/xml; charset=utf-8
}
Response Content : 
<ProductInfo xmlns:i="http://www.w3.org/2001/XMLSchema-instance" xmlns="http://schemas.datacontract.org/2004/07/MessageHandlerDemo01"><CategoryID>1</CategoryID><Discontinued>false</Discontinued><ProductID>2</ProductID><ProductName>牛奶</ProductName><QuantityPerUnit>每箱24瓶</QuantityPerUnit><ReorderLevel>25</ReorderLevel><SupplierID>1</SupplierID><UnitPrice>19</UnitPrice><UnitsInStock>17</UnitsInStock><UnitsOnOrder>40</UnitsOnOrder></ProductInfo>
===============================================
 

2014-08-04 19:05:24.4343 | INFO | TID:11 | 
Request:
Method: GET, RequestUri: 'http://localhost:39553/api/product/34', Version: 1.1, Content: System.Web.Http.WebHost.HttpControllerHandler+LazyStreamContent, Headers:
{
  Connection: keep-alive
  Accept: */*
  Accept-Encoding: gzip
  Accept-Encoding: deflate
  Accept-Encoding: sdch
  Accept-Language: zh-TW
  Accept-Language: zh; q=0.8
  Accept-Language: en-US; q=0.6
  Accept-Language: en; q=0.4
  Host: localhost:39553
  User-Agent: Mozilla/5.0
  User-Agent: (Windows NT 6.1; WOW64)
  User-Agent: AppleWebKit/537.36
  User-Agent: (KHTML, like Gecko)
  User-Agent: Chrome/36.0.1985.125
  User-Agent: Safari/537.36
  MyMessageHandlerHead: SendMessageHandler-20140804190524
  Content-Type: application/json
  Content-Length: 0
}
Request Content:

-----------------------------------------------
Response:
StatusCode: 200, ReasonPhrase: 'OK', Version: 1.1, Content: System.Net.Http.ObjectContent`1[[MessageHandlerDemo01.ProductInfo, MessageHandlerDemo01, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null]], Headers:
{
  Content-Type: application/json; charset=utf-8
}
Response Content : 
{"ProductID":35,"ProductName":"芭樂汁","SupplierID":16,"CategoryID":1,"QuantityPerUnit":"每箱24瓶","UnitPrice":18.0,"UnitsInStock":20,"UnitsOnOrder":0,"ReorderLevel":15,"Discontinued":false}
===============================================
 

2014-08-04 19:05:30.1013 | INFO | TID:12 | 
Request:
Method: GET, RequestUri: 'http://localhost:39553/api/product/45', Version: 1.1, Content: System.Web.Http.WebHost.HttpControllerHandler+LazyStreamContent, Headers:
{
  Connection: keep-alive
  Accept: */*
  Accept-Encoding: gzip
  Accept-Encoding: deflate
  Accept-Encoding: sdch
  Accept-Language: zh-TW
  Accept-Language: zh; q=0.8
  Accept-Language: en-US; q=0.6
  Accept-Language: en; q=0.4
  Host: localhost:39553
  User-Agent: Mozilla/5.0
  User-Agent: (Windows NT 6.1; WOW64)
  User-Agent: AppleWebKit/537.36
  User-Agent: (KHTML, like Gecko)
  User-Agent: Chrome/36.0.1985.125
  User-Agent: Safari/537.36
  MyMessageHandlerHead: SendMessageHandler-20140804190530
  Content-Type: application/json
  Content-Length: 0
}
Request Content:

-----------------------------------------------
Response:
StatusCode: 200, ReasonPhrase: 'OK', Version: 1.1, Content: System.Net.Http.ObjectContent`1[[MessageHandlerDemo01.ProductInfo, MessageHandlerDemo01, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null]], Headers:
{
  Content-Type: application/json; charset=utf-8
}
Response Content : 
{"ProductID":46,"ProductName":"蚵","SupplierID":21,"CategoryID":8,"QuantityPerUnit":"每袋3公斤","UnitPrice":12.0,"UnitsInStock":95,"UnitsOnOrder":0,"ReorderLevel":0,"Discontinued":false}
===============================================

小喵格式沒有特別處理，理論上處理成JSON或者XML，對未來的處理會比較方便

末記：

Message Handler 可對於 WebAPI 的所有進/出(request / response)，進行一些額外的處理，無論是Log或者進出的Header加解密等等，利用他成雙成對，管線(PipeLine)運作、權責分離的這些特性，對於WebAPI的管理來說，提供一個可以額外加工簡單而方便的方式。而NLog對於用來記錄想記錄的資訊，針對不同的狀況，可以分別記錄在文字檔、資料庫、事件紀錄簿等方式，且效能影響不大，使用上很方便。小喵對於這兩者的結合，提供一個範例，自己筆記一下，也提供大家參考。

^_^

以下是簽名：

歡迎轉貼本站的文章，不過請在貼文主旨上加上【轉貼】，並在文章中附上本篇的超連結與站名【topcat姍舞之間的極度凝聚】，感恩大家的配合。
小喵大部分的文章會以小喵熟悉的語言VB.NET撰寫，如果您需要C#的Code，也許您可以試著用線上的工具進行轉換，這裡提供幾個參考

Microsoft MVP
Visual Studio and Development Technologies
(2005~2019/6)

topcat
Blog:http://www.dotblogs.com.tw/topcat

回首頁

topcat 姍舞之間的極度凝聚

世界上有兩樣東西分享給別人後，不但不會變少，還會變更多：一個是快樂，另一個是知識~分享...是知識累積的開始...