ASP.NET Web APIでログを綺麗に出す

井上です。

Web Request/Responseのログをお手軽に出しましょうというお話です。
ログ出力のサンプルは多々あるのですが、パラメータを全部出していたりとかはあんまりないというところから。

環境

Visual Studio Pro 2013
.NET Framework 4.5.3
ASP.NET Web API

Json.NETをGetする

ログ出力クラスを作る

https://msdn.microsoft.com/ja-jp/library/system.web.http.filters.actionfilterattribute(v=vs.118).aspxクラスを継承してOnActionExecutedをオーバーライドします。
最初コントローラーに引き渡されるパラメータをリフレクションしまくってクラスプロパティ値出してましたが、JsonConvertでJson形式で出力する良い感じです。

using Newtonsoft.Json;
using System.Web.Http.Filters;

public class LoggingAttribute : ActionFilterAttribute
{  
    public override void OnActionExecuting(System.Web.Http.Controllers.HttpActionContext actionContext)
    {
        var log = new
        {
            LogType = "OnActionExecuting",
            Controller = actionContext.ControllerContext.Controller.ToString(),
            Method = actionContext.Request.Method.Method,
            RequestUri = actionContext.Request.RequestUri,
            RequestHeaders = actionContext.Request.Headers,
        };
        Logger.WriteLog(Logger.LogLevel.Info, JsonConvert.SerializeObject(log));
        base.OnActionExecuting(actionContext);
    }

    public override void OnActionExecuted(HttpActionExecutedContext actionExecutedContext)
    {
        // 例外発生時は例外フィルターより先に呼び出されるのでResponse値をチェックしたうえで出力する
        var log = new
        {
            LogType = "OnActionExecuted",
            HTTPStatus = (actionExecutedContext.Response == null) ? "" : actionExecutedContext.Response.StatusCode.ToString(),
            Request = actionExecutedContext.Request.ToString(),
            Parameter = actionExecutedContext.ActionContext.ActionArguments,
            Response = (actionExecutedContext.Response == null || actionExecutedContext.Response.Content == null) ? "" : actionExecutedContext.Response.Content.ReadAsStringAsync().Result,
        };
        Logger.WriteLog(Logger.LogLevel.Info, JsonConvert.SerializeObject(log));
        base.OnActionExecuted(actionExecutedContext);
    }
}

System.Web.Http.Filters.ActionFilterAttributeにはOnActionExecutingとOnActionExecutedがありますが、HttpActionExecutedContextにRequestの内容も含まれていますので、OnActionExecutedだけ実装しておけばログ内容としては足りるかと思います。
尚、コード中のLoggerはlog4netを用いたログ出力クラスです。
例フィルターを作る場合はhttps://msdn.microsoft.com/ja-jp/library/system.web.http.filters.exceptionfilterattribute(v=vs.118).aspxクラスを継承してOnExceptionをオーバーライドします。

コントローラーの基底クラスを定義し、フィルターを付ける

基底クラスに以下の通りフィルターを定義しておきます。

[Logging]
public class BaseApiController : ApiController

コントローラーで基底クラスを定義する

    [RoutePrefix("hogehoge")]
    public class HogeHogeController : BaseApiController
    {
        [HttpGet]
        public IHttpActionResult HogeHoGet(string param1, string param2, int param3)
        {
            var result = new
            {
                param1 = "param1は" + param1,
                param2 = "param2は" + param2,
                param3 = "param3は" + param3
            };
            return Ok(result);
        }
    }

ログの確認

http://localhost:61369/hogehoge?param1=sanwa&param2=system&param3=123で呼び出しログを確認します。

OnActionExecutingのログ

{"2016-02-24 13:21:14,195":{"level":"INFO ","message":{"LogType":"OnActionExecuting","Controller":"Ssc.Ttb.Api.Front.Controllers.v1.HogeHogeController","Method":"GET","RequestUri":"http://localhost:61369/hogehoge?param1=sanwa&param2=system&param3=123","RequestHeaders":[{"Key":"Connection","Value":["Keep-Alive"]},{"Key":"Accept","Value":["text/html","application/xhtml+xml","*/*"]},{"Key":"Accept-Encoding","Value":["gzip","deflate"]},{"Key":"Accept-Language","Value":["ja-JP"]},{"Key":"Host","Value":["localhost:61369"]},{"Key":"User-Agent","Value":["Mozilla/5.0","(Windows NT 6.1; WOW64; Trident/7.0; rv:11.0)","like","Gecko"]}]}}}

JSON Viewerで見るとこんな感じです。

OnActionExecutedのログ

{"2016-02-24 13:21:14,195":{"level":"INFO ","message":{"LogType":"OnActionExecuted","HTTPStatus":"OK","Request":"Method: GET, RequestUri: 'http://localhost:61369/hogehoge?param1=sanwa&param2=system&param3=123', Version: 1.1, Content: System.Web.Http.WebHost.HttpControllerHandler+LazyStreamContent, Headers:\r\n{\r\n Connection: Keep-Alive\r\n Accept: text/html\r\n Accept: application/xhtml+xml\r\n Accept: */*\r\n Accept-Encoding: gzip\r\n Accept-Encoding: deflate\r\n Accept-Language: ja-JP\r\n Host: localhost:61369\r\n User-Agent: Mozilla/5.0\r\n User-Agent: (Windows NT 6.1; WOW64; Trident/7.0; rv:11.0)\r\n User-Agent: like\r\n User-Agent: Gecko\r\n}","Parameter":{"param1":"sanwa","param2":"system","param3":123},"Response":"{\"param1\":\"param1はsanwa\",\"param2\":\"param2はsystem\",\"param3\":\"param3は123\"}"}}}

同じくJSON Viewerで見ます。

綺麗に出ました。