ロギングアーキテクチャ
ここからはロギングアーキテクチャについて設計していきましょう。
まずはロギングの要件を明確にします。
ロギング要件
今回は仮に、つぎのような要件があるものとします。
- ログは可能な限り一貫して保管するため、基本的にはサーバーサイドに保管すること
- ただしロギングサーバーが停止している場合も考慮し、エラーレベルのログはローカルファイルシステムにもあわせて保管すること
- ログは将来的な分析に利用するため、構造化ログを利用すること
- ログの出力には、ログ出力を要求した端末・ユーザーの情報を含めること
- ログの出力レベルは、モジュールの再配布なく、サーバーサイドから変更可能であること
WPFアプリケーションの場合、要件5が実現できると、運用時に楽になることがあります。WPFアプリケーションの場合、Webアプリケーションとちがって再配布が容易ではないため、障害などの解析が必要になった際に、ログの出力レベルを再配布なく変更できることは、おおきなメリットとなります。
なお要件4に一部のログ属性について言及していますが、今回はこれ以外の属性については言及しません。特にユーザー情報に関しては、認証処理と密接にかかわってくるため入れましたが、それ以外は実際のプロジェクトにおいて必要に応じて検討してください。
ログ出力レベル設計
さて詳細な設計に入る前に、ログの出力レベルについて決定しておきましょう。ここからは仮の実装を行いながら設計します。出力レベルの認識がずれていると、あとから直すのは負担が大きいためです。
レベル | 通常時出力 | クライアントサイド | サーバーサイド |
---|---|---|---|
Trace | × | Debugレベル以外のViewModelのメソッド呼び出し時 | なし |
Debug | × | ViewModelの画面遷移イベント発生時、またはCommand呼び出し時 | なし |
Information | 〇 | なし | HTTPのリクエスト、レスポンス時。認証後のAPI呼び出し前。 |
Warning | 〇 | アプリケーションの機能に影響を与える可能性のあると判断したとき。個別に相談の上決定し、つど本表を更新する。 | 同左+認証エラー時 |
Error | 〇 | 意図しない例外の発生時 | 同左 |
Critical | 〇 | システムの運用に致命的な問題が発生した場合 | 同左 |
通常はInformationレベル以上は出力し、Debug以下は、障害の調査時などに必要に応じて一時的に利用します。
上記仕様の場合、サーバーサイドで例外が発生した場合、クライアントサイドでもWeb API呼び出しが例外となります。そのため、同一の例外が2重で出力されますが、取りこぼすよりは良いため上記定義とします。
個人的にはWarningの扱いが難しいといつも感じます。単純明快なルールを定められたことがありません。良い提案があればぜひ伺いたいです。
WPF上のTrace、Debugログ
前述のとおり、基本的にViewModelのメソッドの呼び出し箇所でログを仕込みます。ただ、これを抜け漏れ誤りなく実装するのは大変です。
そこで今回はPostSharpというAOPライブラリを利用して、一括でログ出力コードを「編み込み」ます。AOPとはAspect Oriented Programming、アスペクト志向プログラミングのことで、横断的な関心ごとを「アスペクト」として、その関心を必要とする場所に「編み込む」方法論のことです。
詳細な説明はここでは割愛しますが、ここではログ出力処理をアスペクトとしてViewModelのメソッドに埋め込みます。
AOPライブラリは各種ありますが、おおきく2種類のタイプに分けられます。
- プロキシーオブジェクトを作ってメソッド呼び出しをインターセプトするタイプ
- コンパイル時にILを操作するなどして、特定のコードを任意の場所に埋め込むタイプ
PostSharpは後者のタイプのライブラリです。
10種類までのアスペクトであれば無償版でも利用でき、実績も多いため今回はPostSharpを利用します。具体的には、つぎのようなOnMethodBoundaryAspectを継承したアスペクトを作成します。
public class LoggingAspect : OnMethodBoundaryAspect { public static ILogger Logger・・・ public override void OnEntry(MethodExecutionArgs args) { var logLevel = GetLogLevel(args); Logger.Log(logLevel, "{Type}.{Method}({Args}) Entry", args.Method.ReflectedType!.FullName, args.Method.Name, args);
そしてViewModelプロジェクトのAssemblyInfo.csなどに、つぎのように記載します。
using AdventureWorks.Wpf.ViewModel; [assembly: LoggingAspect(AttributeTargetTypes = "*ViewModel")]
これでビルド時にViewModelのメソッドの入り口でLoggingAspectクラスのOnEntryが呼び出されるコードが編み込まれます。非常に簡単ですし、抜け漏れ誤りなく実装が可能になります。
ロギングアーキテクチャ概要
前述の要件を満たすために、ざっくり次のようなアーキテクチャを検討します。
- ロギングのインターフェイスには、Microsoft.Extensions.Loggingを利用する
- ロギングの実装には、Serilogを利用する(要件3)
- ログの出力はSQL Server上に保管する(要件1)
- WPFのログ出力は、SerilogのSink(出力先を拡張する仕組み)を利用してgRPCでサーバーへ送信して保管する(要件1)
- またあわせてエラーレベルのログは、FileSinkを利用してローカルにも出よくする(要件2)
- WPF・Web APIともに、起動時にログ設定ファイルをサーバーより取得して適用する(要件5)
- ログ出力時は認証アーキテクチャで検討した仕組みを適用してユーザーを特定してログ出力する(要件4)
上記を実現するため、ロギングWeb APIをgRPCで構築します。ざっくりした構成はつぎのとおりです。
ロギングAPIも認証を掛けたいため、認証APIを利用します。その上で、次のような相互作用をとります。
まず認証APIを呼び出して認証します。このときビジネスドメインのWeb APIとは別のaudienceを利用します。そのためWPFの起動時にビジネスドメインとロギングで最低2回の認証を呼び出します。
認証に成功したらロギング設定をロギングAPIから取得します。取得時にはビジネスドメインのWeb API同様にJWTで認証します。あとは取得した設定情報に基づいてログを出力します。
ビジネスドメインのWeb APIノードは、その機能の提供時に直接データベースサーバーを利用します。そのためログ出力も直接データベースへ出力します。ロギング時にログAPIを利用してもよいのですが、今回はノードを分散した耐障害性まで求めないものとして、直接データベースに出力することとします。
ロギングのドメインビュー
さて、そろそろ慣れてきてもう気が付いていると思いますが、ロギングも汎用のライブラリ的に扱いますから、新しい汎用ドメインになります。
下図がロギングドメインからみた境界付けられたコンテキストです。
そして下図がコンテキストマップです。
ロギングコンテキストは、購買・製造・販売のコンテキストからカスタマー・サプライヤー関係で利用されます。その際に、認証されたユーザーにのみ利用を許可するため、認証コンテキストとAdventureWorks.Businessコンテキストを利用します。ロギングコンテキストは、WPFクライアントに対してgRPCでロギングAPIを提供するためMagicOnionコンテキストを利用します。そしてログの出力はSqlServerに行うため、データベースコンテキストも利用します。
ロギングの論理ビュー
ではロギングの論理ビューを設計しましょう。
だいたいこんな感じでしょうか? 今回は、中央からAdventureWorks.Businessドメインを省略しています。実際には認証処理のためにUserオブジェクトを参照するのですが、本質的には影響が小さいことと、ロギングドメインの外側にSerilogに直接依存している層を書きたかったので、省略しました。
最外周にMagicOnionが2カ所でてきます。これは別のサービスというわけではなく、片側にそろえると込み合ってしまうので、見やすくするために分けてあるだけです。
上側がログ出力側、下側が初期化処理側のオブジェクトが集まっています。
初期化処理
まずは初期化処理についてみてみましょう。
認証と同様に、アプリケーション起動時に初期画面のViewModelから初期化を行います。
ILoggingInitializerインターフェイスを呼び出すことで初期化を行います。実際にはLoggingInitializerクラスを注入して、クラスを呼び出します。LoggingInitializerは、ISerilogConfigRepositoryインターフェイスを利用して設定をサーバーから取得して、Serilogを初期化します。
ISerilogConfigRepositoryインターフェイスの実体はSerilogConfigRepositoryClientクラスで、IMagicOnionFactoryを利用して、ISerilogConfigServiceインターフェイスの実体を取得して呼び出すことで、gRPCでサーバーサイドを呼び出します。
サーバーサイドではSerilogConfigServiceクラスが呼び出され、ISerilogRepositoryを使って、データベースから設定値を取得します。ISerilogRepositoryインターフェイスの実体はSerilogRepositoryクラスで、このクラスからデータベースを呼び出して実際の設定値を取得します。
実装ビューの設計時に、実際にコードを追いつつ詳細に見たいと思います。
ログ出力処理
ログ出力処理の流れは次の通りです。
ユーザーがViewで何らかの操作をすると、ViewModelが呼び出されます。ViewModelのメソッドの入り口で、PoshSharpによって織り込まれたLoggingAspectが呼び出されて、ログを出力します。
ログ出力を指示されたSerilogは(ここは図には記載していません)、MagicOnionSinkを利用してMagicOnion経由でログを出力します。MagicOnionSinkはIMagicOnionFactoryからILoggingServiceのインスタンスを取得して、サーバーサイドにログを渡します。
サーバーサイドではLoggingServiceがログを受け取り、ILogRepositoryでログを書き込みます。ILogRepositoryインターフェイスの実体はLogRepositoryクラスで、ここで実際にデータベースにログが出力されます。
ロギング実装ビューの設計
では先ほどの登場オブジェクトを、コンポーネントに割り振ってみましょう。
ひとまず問題なさそうです。コードと流れを追って見ていきましょう。
初期化処理
つぎの流れで順番にみていきます。
アプリケーションの起動時、初期画面で認証を実施していた箇所に、ログ出力の初期化処理を追加します。
public class MainViewModel : INavigatedAsyncAware { private readonly ILoggingInitializer _loggingInitializer; ・・・ public async Task OnNavigatedAsync(PostForwardEventArgs args) { var authenticationResult = await _authenticationService.TryAuthenticateAsync(); if (authenticationResult.IsAuthenticated && await _loggingInitializer.TryInitializeAsync()) { await _presentationService.NavigateToMenuAsync(); } else { _presentationService.ShowMessage( Purchasing.ViewModel.Properties.Resources.AuthenticationFailed, Purchasing.ViewModel.Properties.Resources.AuthenticationFailedCaption, MessageBoxButton.OK, MessageBoxImage.Error); // アプリケーションを終了する。 Environment.Exit(1); } } }
DIされたILoggingInitializerを呼び出してロガーを初期化します。初期化に失敗した場合は、ユーザー認証エラーでアプリケーションを終了します。
ILoggingInitializerの実装クラス、LoggingInitializerはつぎの通りです。
public class LoggingInitializer : ILoggingInitializer { private readonly ApplicationName _applicationName; private readonly ILoggerFactory _loggerFactory; ・・・ public async Task<bool> TryInitializeAsync() { // ロギングドメインの認証処理を行う AuthenticationService authenticationService = new(new ClientAuthenticationContext(), LoggingAudience.Instance); var result = await authenticationService.TryAuthenticateAsync(); if (result.IsAuthenticated is false) { return false; } // ロギング設定を取得する MagicOnionClientFactory factory = new(result.Context, Endpoint); var repository = new SerilogConfigRepositoryClient(factory); var config = await repository.GetClientSerilogConfigAsync(_applicationName); #if DEBUG config = config with { MinimumLevel = LogEventLevel.Debug }; #endif // ロガーをビルドする var logger = config.Build(); // ロギング設定を適用する MagicOnionSink.MagicOnionClientFactory = factory; LoggingAspect.Logger = new SerilogLoggerProvider(logger) .CreateLogger(typeof(LoggingAspect).FullName!); return true; } }
ApplicationNameとILoggerFactoryをDIして初期化を行います。ログを出力する際、購買・製造・販売のどのアプリケーションのログが出力したか判別したいため、ApplicationNameを利用します。初期化処理ではまずAuthenticationServiceを利用して、ロギングドメインの認証を行います。
認証が成功したら、SerilogConfigRepositoryClientを利用してリモートから設定情報を取得します。このとき、アプリケーション名を指定して取得します。アプリケーション名を指定することで、個別のアプリケーションごとに設定が変更できるようにします。
設定情報を取得したらロガーをビルドして、MagicOnionSinkとLoggingAspectを初期化します。このとき、開発中はログを詳細にだしておきたいのでデバッグビルド時は、ログレベルを強制的にLogEventLevel.Debugに上書きしています。
LoggingAspectはSerilogには直接依存せず、Microsoft.Extensions.Hosting.Loggingのロガーを利用するため、SerilogLoggerProviderからロガーを生成しています。
全体としてはこのような流れになります。では詳細をもう少し掘り下げて見ていきましょう。
public class SerilogConfigRepositoryClient : ISerilogConfigRepository { private readonly IMagicOnionClientFactory _clientFactory; public async Task<SerilogConfig> GetClientSerilogConfigAsync(ApplicationName applicationName) { var service = _clientFactory.Create<ISerilogConfigService>(); return await service.GetServerSerilogConfigAsync(applicationName.Value);
SerilogConfigRepositoryClientはこれまでのMagicOnionのクライアント実装と相違ありません。IMagicOnionClientFactoryからサービスを生成して、リモートを呼び出します。
呼び出されたリモート側はつぎの通りです。
public class SerilogConfigService : ServiceBase<ISerilogConfigService>, ISerilogConfigService { private readonly ISerilogConfigRepository _repository; public async UnaryResult<SerilogConfig> GetServerSerilogConfigAsync(string applicationName) { return await _repository.GetClientSerilogConfigAsync(new ApplicationName(applicationName)); } }
ISerilogConfigRepositoryを呼び出してその結果を返却しています。実体はSQL Server向けのSerilogConfigRepositoryクラスです。
public class SerilogConfigRepository : ISerilogConfigRepository { ・・・ public async Task<SerilogConfig> GetClientSerilogConfigAsync(ApplicationName applicationName) { return await GetSerilogConfigAsync(applicationName, new ApplicationName("Client Default")); } private async Task<SerilogConfig> GetSerilogConfigAsync( ApplicationName applicationName, ApplicationName defaultName) { using var connection = _database.Open(); const string query = @" select ApplicationName, MinimumLevel, Settings from Serilog.vLogSettings where ApplicationName = @Value"; return await connection.QuerySingleOrDefaultAsync<SerilogConfig>(query, applicationName) ?? await connection.QuerySingleAsync<SerilogConfig>(query, defaultName); } }
ログの設定はアプリケーションごとに定義できると記載しました。ただ、常に個別の設定がしたいわけではなく、通常時はデフォルトの設定を利用しておいて、障害時などに個別に設定が変更できるようにしたいです。
そのため、GetClientSerilogConfigAsyncを呼び出すと"Client Default"をデフォルト設定名として内部でGetSerilogConfigAsyncを呼び出しています。
まずは指定されたアプリケーション名で取得してみて、個別の定義がなければ"Client Default"の設定を取得して返却します。
SQLの中でSettings列が指定されていますが、ここに通常は設定ファイルに記載するフォーマットで設定を格納しておきます。これによってデータベース側の設定を更新することで、すべてのWPFアプリケーションに適用されるログ設定を変更可能にします。
取得した設定は、クライアント側でビルドされてロガーインスタンスを生成します。
public record SerilogConfig(ApplicationName ApplicationName, LogEventLevel MinimumLevel, string Settings) { public ILogger Build() { var settingString = Settings .Replace("%MinimumLevel%", MinimumLevel.ToString()) .Replace("%ApplicationName%", ApplicationName.Value); using var settings = new MemoryStream(Encoding.UTF8.GetBytes(settingString)); var configurationRoot = new ConfigurationBuilder() .AddJsonStream(settings) .Build(); global::Serilog.Log.Logger = new LoggerConfiguration() .ReadFrom.Configuration(configurationRoot) #if DEBUG .WriteTo.Debug() #endif .CreateLogger(); return global::Serilog.Log.Logger; } }
Settingsにはログレベルやアプリケーション名が変更できるように、置換文字列で記載しておいて、ビルド時に値を置き換えます。
その上で、置き換えられた設定からConfigurationBuilderを利用して設定オブジェクトをビルドします。そしてビルドされた設定からSerilogのロガーを生成します。
このとき、やはりデバッグ時はVisual StudioのDebugコンソールにも出したいので、WriteTo.Debug()を追加しています。
初期化処理はおおむねこの通りです。
ログ出力処理
ではログ出力側のコードを見ながら流れを確認していきましょう。
先に説明した通り、ログの出力はViewModelのメソッド入り口で行われます。ただ個別に実装するわけではなく、LoggingAspectを織り込むことで行われます。
[PSerializable] public class LoggingAspect : OnMethodBoundaryAspect { public static ILogger Logger { get; set; } = new NullLogger<LoggingAspect>(); public override void OnEntry(MethodExecutionArgs args) { var logLevel = GetLogLevel(args); Logger.Log(logLevel, "{Type}.{Method}({Args}) Entry", args.Method.ReflectedType!.FullName, args.Method.Name, args); } private static LogLevel GetLogLevel(MethodExecutionArgs args) { return args.Method.Name.StartsWith("On") || args.Method.GetCustomAttributes(true).Any(a => a is RelayCommandAttribute) ? LogLevel.Debug : LogLevel.Trace; } }
OnMethodBoundaryAspectのOnEntryをオーバーライドすることで、メソッドの呼び出しをフックします。呼び出されたメソッドをGetLogLevelに渡して、ログの出力レベルを判定します。画面遷移時とコマンドの呼び出し時はDebug、それ以外はTraceで出力する仕様なので、そのように判定します。
Kamishibaiを利用する場合、画面遷移イベントはOn~というメソッドを利用するためそれで判断します。画面遷移イベント以外にOn~を使うことは避けますが、Debugレベルのログは通常時は出力しないため、少々別のものが紛れ込んでも問題ないでしょう。
ViewModelのコマンドは、CommunityToolkit.Mvvmライブラリを利用して行います。具体的にはつぎのように記載します。
[RelayCommand] private Task GoBackAsync() => _presentationService.GoBackAsync();
メソッドにRelayCommandAttributeを宣言することで、コード生成を利用して自動的にコマンドが作成されます。非常に便利なのでオススメです。このようにコマンドを自動生成するため、メソッドにRelayCommandAttributeが宣言されているかどうかで、コマンドの呼び出しかどうかを判定しています。
LoggingAspectからILoggerを呼び出すと、内部的にMagicOnionSinkが呼び出されます。
public class MagicOnionSink : ILogEventSink { private readonly LogEventLevel _restrictedToMinimumLevel; public async void Emit(LogEvent logEvent) { if (logEvent.Level < _restrictedToMinimumLevel) { return; } var service = MagicOnionClientFactory.Create<ILoggingService>(); await service.RegisterAsync( new LogDto( ・・・ )); } }
先頭で呼び出されたログの出力レベルが、出力条件を満たしているか判定し、見たいしていない場合は早期リターンします。条件を満たしたレベルであれば、MagicOnionClientFactoryを利用してILoggingServiceを生成し、リモートにログを送信します。
ここは細かな文字列編集などが多いため、一部のコードを省略していますので、詳細に興味があるかたはGitHubを直接ご覧ください。ログを送信されたサーバー側は次のとおりです。
public class LoggingService : ServiceBase<ILoggingService>, ILoggingService { private readonly ILogRepository _eventRepository; private readonly IAuthenticationContext _authenticationContext; public LoggingService( ILogRepository eventRepository, IAuthenticationContext authenticationContext) { _eventRepository = eventRepository; _authenticationContext = authenticationContext; } public async UnaryResult RegisterAsync(LogDto logRecord) { await _eventRepository.RegisterAsync( new Log( ・・・ )); } }
JWTによる認証情報と、ILogRepositoryを利用してSQL Serverにログを保管します。ILogRepositoryの実装は繰り返しになるため、省略します。こうしてログの出力設定をデータベース側に保管しておいて、任意のタイミングで出力レベルを調整できるようにしています。
その上でWPFアプリケーションの個別機能の実装側で特別な実装を行うことなく、抜け漏れ誤りなくログが出力できるようになりました。
ロギング配置ビューの設計
それでは実装ビューで導出したコンポーネントをノード上に配置しましょう。特に難しい要素もなく、これまでの繰り返しになってしまうため、さらっと説明します。実装ビューのコンポーネントをノード上に配置したものが以下の図です。
初期化処理時のシーケンスをたどってみましょう。
問題ありませんね。ロギング処理時のパスも、ViewModelからのほぼ同様なので説明は割愛します。1点補足があるとすると、購買API側のログ出力は、SerilogのSqlServerSinkを直接使うことです。そのため、特別な仕組みは必要ありません。
まとめ
今回は、非機能要件に関するアーキテクチャ設計を行いました。先に非機能がある程度設計されていた方が、ユースケースの設計を行うのが容易になる側面があります。
ユースケースの設計をするのに認証が必要になることは多いでしょうし、設計中に仮実装する上で、例外処理やロギングが提供されていた方がデバッグもやりやすくなります。そのため、私個人としてはこのあたりの非機能の設計はユースケースを掘り下げる前にある程度の品質で設計されていたほうがやりやすいと感じています。
もちろん、ユースケースを設計していく上で、これらの設計が変更になることはあります。しかしアーキテクチャを設計していく上で、ことなる要件を設計していくことで、ほかの設計の見直しが必要になることは、よくあることです。これは必要なコストと考えた方が良いでしょう。そのコストはWPFならWPFのアーキテクチャが一度ある程度に詰まると、次の開発では再利用可能な範囲が広いため、徐々に品質もコストも改善していくのが良いと考えています。
さて、次回はいよいよ最終回である「設計編/後編」になります。後編では、特定のユースケースを実現するアーキテクチャの設計と、開発環境を中心としたアーキテクチャについて解説したいと思います。それでは、また次回お会いしましょう!