ASP.NET Core でコントローラーやサービスの実行時にログを自動挿入する
はじめに
ASP.NET Core で実行するサービスのログをサービスごとに書くのではなく共通処理としてログを出力したいと考えます。
初期コード
以下のようにシンプルなコントローラーとサービスがあるとします。
public interface IMyService
{
}
public class MyService() : IMyService
{
}
public class MyController(IMyService service) : ControllerBase
{
}
var builder = WebApplication.CreateBuilder(args);
builder.Services.AddControlers();
builder.Services.AddScoped<IMyService, MyService>();
ここで、コントローラーやサービスに対して変更を加えることなく、コントローラーやサービスの処理の前後にログを挿入することを考えます。
コントローラーに対するログの挿入
アクションフィルター
コントローラーについてはアクションフィルターを利用することで、コントローラーの処理前後に対して処理を埋め込むことができます。
アクションフィルターには同期型の IActionFilter と非同期型の IAsyncActionFilter の 2 種類のインターフェイスがありますが、いずれかを実装すれば良いです。同期型のインターフェイスは処理の前後が別のメソッドに分かれているのに対して非同期型はアクションの実行を含めて 1 つのメソッドにで処理できるためログの流れを記述するのは非同期型の方が簡単です。
public class LoggingActionFilter(ILogger<LoggingActionFilter> logger) : IAsyncActionFilter
{
public async Task OnActionExecutionAsync(ActionExecutingContext context, ActionExecutionDelegate next)
{
try
{
logger.LogInformation("コントローラー開始");
await next();
logger.LogInformation("コントローラー成功");
}
catch
{
logger.LogInformation("コントローラー例外");
throw;
}
finally
{
logger.LogInformation("コントローラー終了");
}
}
}
アクションフィルターの利用
アクションフィルターを利用するには、 MvcOptions の構成でフィルターを追加します。コード例は最後に示します。
サービスに対するログの挿入
DispatchProxy
ASP.NET Core では、サービスについてはコントローラーの ActionFilter のような仕組みは提供されていないため、自前で実装する必要があります。そこで DispatchProxy クラスを利用して、任意のインターフェイスに対してメソッド実行時の処理を委譲させることを考えます。
DispatchProxy の利用イメージを以下に示します。
var proxyService = DispatchProxy.Create<TService, TProxy>();
proxyService.ServiceMethod();
ここで TService はサービスインターフェイス、 TProxy は DispatchProxy を継承したクラスで す。 proxyService.ServiceMethod() を呼び出すと、 DispatchProxy の抽象メソッド Invoke 経由で実行されます。したがって、 DispatchProxy を継承したクラスで任意の処理を挿入することで、インターフェースメソッドの呼び出し時に任意の処理を共通処理として実行することができるということです。
例えばログを挿入する DispatchProxy の実装は、以下のように書くことができます。
public class LoggingServiceProxy<TService> : DispatchProxy
where TService : class
{
private TService _service = default!;
private ILogger _logger = default!;
public static TService Create(Func<TService> implementationFactory, IServiceProvider serviceProvider)
{
var service = Create<TService, LoggingServiceProxy<TService>>();
var proxy = (LoggingServiceProxy<TService>)(object)service;
proxy._service = implementationFactory();
proxy._logger = serviceProvider.GetRequiredService<ILogger<LoggingServiceProxy<TService>>>();
return service;
}
protected override object? Invoke(MethodInfo? targetMethod, object?[]? args)
{
try
{
_logger.LogInformation("サービス開始");
var result = targetMethod?.Invoke(_service, args);
_logger.LogInformation("サービス成功");
return result;
}
catch (TargetInvocationException ex)
{
_logger.LogInformation("サービス例外");
if (ex.InnerException != null)
{
throw ex.InnerException;
}
throw;
}
finally
{
_logger.LogInformation("サービス終了");
}
}
}
この例では LoggingServiceProxy のメンバーに TService の実装と ILogger を持たせておき、 Invoke メソッドの実装として実際のサービスのメソッドの実行およびログの出力を行っています。注意すべき点として、 targetMethod.Invoke では実装メソッド内で例外が投げられた場合に TargetInvocationException でラップされて送出されるため、一度キャッチしてから内部例外を再スローする必要があります。そうしないと、サービス利用側（ここではコントローラー）における例外処理でプロキシーの存在を意識しなければならなくなります。
DispatchProxy の依存性注入
実際にアプリケーション内で各サービスの利用時に LoggingServiceProxy<TService> を利用するためには、 IServiceProvider.Get(Required)Service<TService> に対して TService の真の実装クラス TImplementation クラスではなく LoggingServiceProxy<TService> が呼び出される必要があります。そのためサービスコレクションの構築について少し工夫が必要になります。
IServiceCollection の拡張メソッド Add(Singleton|Scoped|Transient) のジェネリックメソッドには以下の 4 つがあります。これらに対応するプロキシー構成を行う拡張メソッドを作ってやれば良いでしょう。
- Add(Singleton|Scoped|Transient)<TService>()
- Add(Singleton|Scoped|Transient)<TService, TImplementation>()
- Add(Singleton|Scoped|Transient)<TService>(Func<IServiceProvider, TService>)
- Add(Singleton|Scoped|Transient)<TService, TImplementation>(Func<IServiceProvider, TImplementation>)
このうち最初の Add(Singleton|Scoped|Transient)<TService>() については、 TService がクラスである必要がありますが、 DispatchProxy ではクラスに対してプロキシーインスタンスを作成することができないため、対応することができません。残りの 3 つについては、サービスのインスタンス化を作成する際に LoggingServiceProxy<TService>.Create で作成したプロキシーインスタンスを返すようにしてやれば良いです。
public static class ServiceCollectionExtensions
{
public static IServiceCollection Add(Singleton|Scoped|Transient)LoggingProxy<TService, TImplementation>(this IServiceCollection services)
where TService : class
where TImplementation : class, TService
{
return services
.Add(Singleton|Scoped|Transient)<TImplementation>()
.Add(Singleton|Scoped|Transient)(serviceProvider => LoggingServiceProxy<TService>.Create(serviceProvider.GetRequiredService<TImplementation>, serviceProvider));
}
public static IServiceCollection Add(Singleton|Scoped|Transient)LoggingProxy<TService>(this IServiceCollection services, Func<IServiceProvider, TService> implementationFactory)
where TService : class
{
return services
.Add(Singleton|Scoped|Transient)(serviceProvider => LoggingServiceProxy<TService>.Create(() => implementationFactory(serviceProvider), serviceProvider));
}
public static IServiceCollection Add(Singleton|Scoped|Transient)LoggingProxy<TService, TImplementation>(this IServiceCollection services, Func<IServiceProvider, TImplementation> implementationFactory)
where TService : class
where TImplementation : class, TService
{
return services
.Add(Singleton|Scoped|Transient)(implementationFactory)
.Add(Singleton|Scoped|Transient)(serviceProvider => LoggingServiceProxy<TService>.Create(serviceProvider.GetRequiredService<TImplementation>, serviceProvider));
}
}
TService 型の実装クラスである TImplementation 型を明示的に指定する場合はあらかじめ TImplementation 型に対する依存性注入を行っておきます。
最終コード
最初の目標通り、コントローラーやサービスに対しては変更が不要で、 Program.cs の変更だけで済みます。
コントローラーについては Configure<MvcOptions>(Action<MvcOptions>) もしくは AddControllers(Action<MvcOptions>) でフィルターを追加します。
builder.Services.Configure<MvcOptions>(options =>
{
options.Filter.Add<LoggingActionFilter>();
});
builder.Services.AddControllers(options =>
{
options.Filter.Add<LoggingActionFilter>();
});
AddScoped としていたサービスの依存性注入を AddScopedLoggingProxy で置き換えるだけでサービスの実行時にログが自動で挿入されるようになります。
builder.Services.AddScopedLoggingProxy<IMyService, MyService>();
最終的には以下のようになります。最初のコードからほとんど変更ありませんが、強力なフィルターやプロキシーの仕組みにより複雑な処理を実現できています。
var builder = WebApplication.CreateBuilder(args)
builder.Services.AddLogging();
builder.Services.AddControllers(configuration =>
{
configuration.Filters.Add<LoggingActionFilter>();
});
builder.Services.AddScopedLoggingProxy<IMyService, MyService>();
Discussion