ASP.NET Web APIのOnActionExecutingは「いつ」動くのか？

はじめに

こんにちは！
ネクスタで開発エンジニアをしている伊藤です。現在は、生産管理システム SmartF の Blazor版移行に携わっています。
初めての投稿になる今回は、アクションメソッドに付けるカスタム属性に関する仕組みをご紹介します。

背景

最近、ASP.NET Web API のコードを読んでいて、[Logging] や [HttpRequestLogFilter] 、[HttpRequestStockFilter] といったカスタム属性がアクションメソッドに付与されているのを見つけました^[1]。

// カスタム属性とアクションメソッドのイメージ
[Logging]
[HttpRequestLogFilter]
[HttpRequestStockFilter]
public IHttpActionResult GetSomeData(int id) 
{
    // メソッド本体の処理
    return Ok(data);
}

アクションメソッド本体の引数は id だけで、ロジックもシンプルです。それなのに、これらの属性が付与されているだけで、実際には「リクエストのログが出力され」 、「パフォーマンス計測が開始され」 、「リクエスト情報がDIコンテナ経由で共有される」 といった、多くの"暗黙の処理"が実行されていました。

私は「処理はメソッド内に書くもの」と強く思い込んでいたため、このように属性（フィルター）を使って、アクション本体とは別の処理—いわゆる「横断的関心事 」—を差し込む仕組みがあることに、最初は戸惑いました。

これらの処理はすべて、コントローラーのアクション実行前後に共通処理を挟み込めるActionFilterAttribute の OnActionExecuting や OnActionExecuted メソッドをオーバーライドすることで実現されています。

そこで今回、私と同じように ActionFilterAttribute の挙動に戸惑う人に向け、
挙動のタイミングと使い道を理解できる記事を書こうと思い立ちました。

目的

この記事では、この「アクション実行前後に割り込む」OnActionExecuting や OnActionExecuted の具体的なタイミングと、その使い道を理解することを目的とします。

• 対象読者:
  • OnActionExecuting や OnActionExecuted がいつ動くのか正確に理解したい人。
  • ログ出力やパフォーマンス計測のような「横断的関心事」を実装したい人。
  • 過去の自分のように「属性を付けるだけでなぜ色々な処理が動くのか？」と疑問に思った人。
• ゴール:
  • 最小限のサンプルコードを通じて、OnActionExecuting や OnActionExecuted が 「コントローラーのアクションメソッド本体が実行される直前」 に呼び出されることを体感的に理解する。
  • OnActionExecuting OnActionExecuted の具体的な使い道を知る。

最小実行サンプル

OnActionExecuting OnActionExecuted の実行タイミングを確かめるため、ログを出力するだけのシンプルなフィルターと、それを使うコントローラーを作成します。

環境

• Visual Studio 2022
• .Net Framework 4.8
• プロジェクトの種類: ASP.NET Web アプリケーション
• テンプレート: Web API

動くコード全体

まず、実行タイミングをコンソール（またはデバッグ出力）に書き出すだけの、非常にシンプルなフィルター TimingLogFilterAttribute を作成します。

TimingLogFilterAttribute.cs

using System.Diagnostics;
using System.Web.Http.Controllers;
using System.Web.Http.Filters;

namespace WebAPISample.Filters
{
    // ActionFilterAttributeを継承する
    public class TimingLogFilterAttribute : ActionFilterAttribute
    {
        // OnActionExecuting をオーバーライドする
        public override void OnActionExecuting(HttpActionContext context)
        {
            // アクションが実行される「前」にログを出力
            Debug.WriteLine("★ 1. OnActionExecuting が実行されました。");

            // （参考）ベースクラスのメソッド呼び出し
            base.OnActionExecuting(context);
        }

        // （比較のため OnActionExecuted も実装）
        public override void OnActionExecuted(HttpActionExecutedContext context)
        {
            // アクションが実行された「後」にログを出力
            Debug.WriteLine("★ 3. OnActionExecuted が実行されました。");

            base.OnActionExecuted(context);
        }
    }
}

次に、このフィルターを適用するコントローラーを用意します。

ValuesController.cs

using System.Collections.Generic;
using System.Diagnostics;
using System.Web.Http;
using WebAPISample.Filters; // 作成したフィルターを using

namespace WebAPISample.Controllers
{
    public class ValuesController : ApiController
    {
        // メソッドに自作フィルターを属性として付与
        [TimingLogFilter]
        public IEnumerable<string> Get()
        {
            // アクションメソッド本体が実行されたタイミングでログを出力
            Debug.WriteLine("★ 2. Controller Action (Get) が実行されました。");
            
            return new string[] { "value1", "value2" };
        }
    }
}

実行結果の確認

1. アプリケーションをデバッグ実行します。
2. GET /api/values エンドポイントにリクエストを送ります。
3. Visual Studio の「出力」ウィンドウを確認します。

以下のような順序でログが出力されるはずです。

★ 1. OnActionExecuting が実行されました。
★ 2. Controller Action (Get) が実行されました。
★ 3. OnActionExecuted が実行されました。

この結果から、OnActionExecuting は ValuesController の Get メソッドが実行される直前 (★1) に呼び出されていることが明確にわかります。一方 OnActionExecuted は Getメソッドが実行された直後 (★3) に呼び出されていることが分かります。

なぜこのタイミングなのか？

これらは、アクションメソッドの実行前後などに、特定のロジックを割り込ませるための機能 アクションフィルター の一種です^[2]。

今回例示したOnActionExecutingとOnActionExecutedは...
OnActionExecuting:アクション メソッドの呼び出し前に呼び出されます。
OnActionExecuted:アクション メソッドが戻った後に呼び出されます。

そのため、処理の流れは以下のようになります。

1. OnActionExecuting の実行
2. アクションメソッド本体の実行
3. OnActionExecuted の実行

つまり OnActionExecuting や OnActionExecuted を使うことで、アクションに渡される引数を変更できたり、アクションから返された結果を変更できたりします。

OnActionExecuting の具体的な使い道

このタイミングは、アクション本体のロジックとは直接関係ない「横断的関心事」を処理するのに最適です。例えば...

1. リクエストログ出力とIPベースのアクセス制御
   LoggingAttribute の例では、リクエスト情報を収集してイベントログに記録しています 。さらに、特定のController へのアクセスかどうかを判定し、特定のIPアドレス以外からのアクセスだった場合は、アクション本体を実行する直前に処理を中断させ、401 Unauthorized を返しています 。

2. パフォーマンス計測用のタイマー開始
   HttpRequestLogFilterAttribute の例では、DIコンテナから IHttpRequestLogger を取得し、タイマーを開始しています 。アクション本体が実行される直前にタイマーをスタートすることで、後続の処理（アクション本体＋OnActionExecuted まで）の実行時間を正確に計測できます。

3. HTTPリクエストの保存（DI経由での共有）
   HttpRequestStockFilterAttribute の例では、アクション本体が実行される直前に現在のHTTPリクエストオブジェクトを、DIコンテナから取得した IHttpRequestMessageAccessor サービスに格納しています 。これにより、同じリクエストスコープ内で動作する他のクラス（例えばリポジトリ層やサービスクラス）が、DIコンテナ経由で現在のリクエスト情報（ヘッダーなど）にアクセスできるようになります。

これらはすべて、OnActionExecuting OnActionExecuted といったアクションフィルターを駆使し、 アクションメソッド本体のコードを汚すことなく、アプリケーション全体で共通の機能を追加することを実現しています。

まとめ

この記事では、フィルターパイプラインの一つ、OnActionExecutingとOnActionExecutedの実行タイミングと、その具体的な使い道についてまとめました。

脚注

1. 実際は HttpFilterCollectionクラス Add()メソッドで予めコレクションに追加してグローバルに使えるようになっているため、毎回[Logging][HttpRequestLogFilter][HttpRequestStockFilter]属性は付けていません。

2. ActionFilterAttribute クラス参照。 ちなみにASP.NET Core版のフィルターの説明は こちら。ASP.NET Web API (.NET Framework)とASP.NET Coreではフィルターの仕組みや種類が異なるためご注意ください。