ASP.NET Core MVCでRequestとResponseのBodyをログ出力する

結論

以下の３つ実装すれば取得できる。

① Streamの読み取りを何回でも可能にするためにカスタムMiddlewareを実装する

RequestEnableBuffering.cs

public class RequestEnableBufferingMiddleware : IMiddleware
{
    public async Task InvokeAsync(HttpContext context, RequestDelegate next)
    {
        context.Request.EnableBuffering();
        await next(context);
    }
}

② ログを出力するためにActionFilterを実装する

LoggerFIlter.cs

public class LoggerFilter : IAsyncActionFilter
{
    async Task IAsyncActionFilter.OnActionExecutionAsync(ActionExecutingContext context, ActionExecutionDelegate next)
    {
        context.HttpContext.Request.Body.Position = 0;
        using var requestReader = new StreamReader(context.HttpContext.Request.Body);
        var requestText = await requestReader.ReadToEndAsync();
        Console.WriteLine(JsonSerializer.Serialize(requestText)); 
        context.HttpContext.Request.Body.Position = 0;

        var executedContext = await next();
        if (executedContext.Result is ObjectResult objectResult)
        {
            Console.WriteLine(JsonSerializer.Serialize(objectResult.Value)); 
        }
    }
}

③ Global FilterとMiddlewareを使用するように設定する

builder.Services.AddControllers(
    option =>
    {
        // Global Filters
        option.Filters.Add<LoggerFilter>();
    });
builder.Services.AddSingleton<RequestEnableBufferingMiddleware>();

// --- この間にその他のServiceのDI ---

// --- この間にその他のServiceのDI ---

var app = builder.Build();

// --- この間にその他のMiddlewareのUse ---

// --- この間にその他のMiddlewareのUse --- 

// MapControllersの前にMiddlewareを追加
app.UseMiddleware<RequestEnableBufferingMiddleware>();
    
app.MapControllers();

app.Run(url);

解説

Responseに関してはResultをキャストするだけで取得できるので、Requestの取得方法について解説する。

ネットで検索すると以下の関数をLoggerFilterの中で呼び出すコードが出てくる。

context.HttpContext.Request.EnableBuffering();

HttpRequestのBodyはStreamになっておりデフォルトでは一回しかReadできない。一方で、その一回はControllerがBodyの情報を取得するために使用する。なので、ログ用にBodyの中身を取得するには、Streamを複数回Readできるようにする必要がある。この複数回Readできるようにする関数がEnableBuffering()である。EnableBuffering()を実行することでReadした後にStreamが指すポインタを以下のコードで戻せるようになる。

context.HttpContext.Request.Body.Position = 0;

では上の二行をLoggerFilter内に実装すれば良いかというと実はそれでは上手くいかない。公式ドキュメントにもあるようにActionFilterに到達するタイミングでは既にModelBindingが完了しているため、ActionFilter内で上記設定を行なっても手遅れなのだ。したがって、ModelBindingより前にEnableBuffering()を実行する必要がある。そこで、Middlewareを追加しEnableBuffering()を行うというのがこの記事の本題だ。

Middlewareの処理順は自分がProgram.csやStartup.csでUseMiddleware<T>()を呼び出した順序できまる（厳密にいうとUse()関数です）。この辺は、公式のドキュメントを読むとわかる。今回はActionFilterの前に呼ばれさえすれば良いので、MapControllersの前に呼ぶのが適切だろう。なので、RequestEnableBufferingMiddleware.csを実装しMapControllersの前でUseMiddleware()を行う。

以上それらを合わせると最終的に結論で書いたようなコードとなる。最後に、今回はBodyをReadする方法をメインで解説しているが本番のコードでログを実装する場合は以下も検討した方が良い。

構造化ロギング
ILoggerの使用
ログ処理のエラーの握りつぶし

おまけ

構造化ロギングを行うときに呼び出されたRequestに紐づくControllerの引数の型情報が必要になることがある。その場合以下のコードで取得することができる。

async Task IAsyncActionFilter.OnActionExecutionAsync(ActionExecutingContext context, ActionExecutionDelegate next)
{
    var controller = context.Controller as ControllerBase;
    var parameters = controller.ControllerContext.ActionDescriptor.Parameters;
}

az blog

UnityやASP.NET Core、それらの周辺技術についてまとめていきます。

ASP.NET Core MVCでRequestとResponseのBodyをログ出力する

結論

解説

おまけ