VB.NETとログについての伺か
はじめに
弊社はロギングライブラリとかの扱いについて割と長い間悩んでいたのですが、自分の中のとりあえずの答えが出たので今回はそんな感じです。
ログライブラリへの強依存
さて、弊社はログライブラリとしてNLogに慣れ親しんでいるのでサンプル中で使うライブラリとしてNLogを使用しますが、Serilogやlog4netを使用しても大して変わらないと思います。たぶん*1
さて、NLogでログを取得するコードを書くとすると以下のような感じになるのではないでしょうか。
Module Module1 Sub Main() Dim model = New SomeModel() Console.WriteLine($"{model.Add(1, 2)}") Console.WriteLine($"{model.Subtract(2, 1)}") Console.WriteLine($"{model.Subtract(1, 2)}") End Sub End Module Class SomeModel Private Shared ReadOnly Logger As NLog.ILogger = NLog.LogManager.GetCurrentClassLogger() Function Add(x As Integer, y As Integer) As Integer Dim result = x + y Logger.Info("{0} + {1} = {2}", x, y, result) Return result End Function Function Subtract(x As Integer, y As Integer) As Integer Dim result = x - y If result < 0 Then Logger.Warn("{0} - {1} is negative ({2})", x, y, result) Return 0 Else Logger.Info("{0} - {1} = {2}", x, y, result) Return result End If End Function End Class
はい、そうですね。べっとりNLogに依存しちゃってます。 仮に他のロギングライブラリに移行することになった場合、ロギングコードを修正する必要が出てきますし、細かくログを取得しようとしていた場合には修正箇所は相当な数になるはずです。
インタフェース化とIoCコンテナ
はいはいインターフェースインターフェース。 メソッドをインターフェースに切り出すことができればあとはIoCコンテナとかを使って外部からロガーを注入してみんなハッピーになれます。
と、ここで壁にぶち当たりました。
どのようなメソッドとしてインタフェースを切り出しましょう
NLogやSerilog、log4netではログの書き出しメソッドはログレベルとして実装されています。 まずはログレベルで検討してみましょう。
NLog | Serilog | log4net | 簡単な説明 |
---|---|---|---|
Trace | Verbose | 該当なし | めっちゃ細かい |
Debug | Debug | Debug | デバッグ情報 |
Info | Information | Info | 通常のイベント情報 |
Warn | Warning | Warn | クリティカルではない警告 |
Error | Error | Error | エラー |
Fatal | Fatal | Fatal | ちょー致命的 |
という感じで多少であるものの、各ロギングライブラリで使用できるログレベルには差異があります。
また、NLogとlog4netはメッセージを出力するタイプのログライブラリですが、Serilogは構造化ログライブラリなのでインターフェースでメソッドのシグネチャを統一しても幸せになれそうではありません。
ではどのようなインタフェースを用意すればいいのかと言いますと、ログイベントを意味論としてメソッドを用意してあげれば良いのではとの結論に至りました。
先ほどの例ですと、以下のような感じになります。
Interface IMyLogger Sub CalcAdd(x As Integer, y As Integer, result As Integer) Sub CalcSubtract(x As Integer, y As Integer, result As Integer) Sub SubtractResultIsNegative(x As Integer, y As Integer, result As Integer) End Interface
この方法ですとプロジェクトごとにインターフェースが異なりますが、そもそもログイベントもプロジェクトごとに異なるんだからそもそもプロジェクトにまたがって共通化する必要はありませんよね。
また、イベントの種類だけメソッドが増大するという問題もありますが、そちらは、まぁ、その、いい感じにお願いします。
そんな感じで、Simple Injectorを使いつつ書き直したのが以下になります。
Imports NLog Imports SimpleInjector Module Module1 Sub Main() Dim c = New Container() Dim logger = New MyLogger(LogManager.GetCurrentClassLogger()) c.RegisterSingleton(Of IMyLogger)(logger) c.Register(Of SomeModel)() c.Verify() Dim model = c.GetInstance(Of SomeModel)() Console.WriteLine($"{model.Add(1, 2)}") Console.WriteLine($"{model.Subtract(2, 1)}") Console.WriteLine($"{model.Subtract(1, 2)}") End Sub End Module Class SomeModel Private ReadOnly _logger As IMyLogger Sub New(logger As IMyLogger) _logger = logger End Sub Function Add(x As Integer, y As Integer) As Integer Dim result = x + y _logger.CalcAdd(x, y, result) Return result End Function Function Subtract(x As Integer, y As Integer) As Integer Dim result = x - y If result < 0 Then _logger.SubtractResultIsNegative(x, y, result) Return 0 Else _logger.CalcSubtract(x, y, result) Return result End If End Function End Class Interface IMyLogger Sub CalcAdd(x As Integer, y As Integer, result As Integer) Sub CalcSubtract(x As Integer, y As Integer, result As Integer) Sub SubtractResultIsNegative(x As Integer, y As Integer, result As Integer) End Interface Class MyLogger Implements IMyLogger Private ReadOnly _nlog As ILogger Public Sub New(logger As ILogger) _nlog = logger End Sub Public Sub CalcAdd(x As Integer, y As Integer, result As Integer) Implements IMyLogger.CalcAdd _nlog.Info("{0} + {1} = {2}", x, y, result) End Sub Public Sub CalcSubtract(x As Integer, y As Integer, result As Integer) Implements IMyLogger.CalcSubtract _nlog.Info("{0} - {1} = {2}", x, y, result) End Sub Public Sub SubtractResultIsNegative(x As Integer, y As Integer, result As Integer) Implements IMyLogger.SubtractResultIsNegative _nlog.Warn("{0} - {1} is negative ({2})", x, y, result) End Sub End Class
この辺のアイデアは弊社が独自で思いついたというよりはSLABの概念とかLightNodeのコードをパクった参考にしたところがあるのでオリジナルへのリンクを付け加えておきます。
余談(ってほど余談でもない)
NLogの${callsite}
とかのスタックフレームのスキップ
<target xsi:type="ColoredConsole" name="console" layout="${longdate} ${uppercase:${level}} ${message}${newline}${stacktrace}${newline}${callsite}" />
みたいなレイアウトを設定している場合、出力結果は
2017-05-06 01:26:54.5080 INFO 1 + 2 = 3 Module1.Main => SomeModel.Add => MyLogger.CalcAdd ConsoleApp2.MyLogger.CalcAdd 3 2017-05-06 01:26:54.5281 INFO 2 - 1 = 1 Module1.Main => SomeModel.Subtract => MyLogger.CalcSubtract ConsoleApp2.MyLogger.CalcSubtract 1 2017-05-06 01:26:54.5281 WARN 1 - 2 is negative (-1) Module1.Main => SomeModel.Subtract => MyLogger.SubtractResultIsNegative ConsoleApp2.MyLogger.SubtractResultIsNegative 0
みたいになって、ログの実装クラスがしゃしゃり出てきてもんにょりします。
そんな時はskipFrames=Integer
を設定してあげるといい感じになります。
<target xsi:type="ColoredConsole" name="console" layout="${longdate} ${uppercase:${level}} ${message}${newline}${stacktrace:skipFrames=1}${newline}${callsite:skipFrames=1}" />
2017-05-06 01:30:57.3469 INFO 1 + 2 = 3 Module1.Main => SomeModel.Add ConsoleApp2.SomeModel.Add 3 2017-05-06 01:30:57.3700 INFO 2 - 1 = 1 Module1.Main => SomeModel.Subtract ConsoleApp2.SomeModel.Subtract 1 2017-05-06 01:30:57.3700 WARN 1 - 2 is negative (-1) Module1.Main => SomeModel.Subtract ConsoleApp2.SomeModel.Subtract 0
IoCコンテナとサービスロケーター
IoCコンテナを使い始めると
コンテナをコンストラクタ引数で渡して、コンテナから必要なオブジェクトを取り出せばいいんだ
みたいに勘違いしやすいと思います。というよりは弊社は勘違いしていました。
今回ので例を示すとこんな感じですね。
Class SomeModel Private ReadOnly _logger As IMyLogger Sub New(container As Container) _logger = container.GetInstance(Of IMyLogger)() End Sub Function Add(x As Integer, y As Integer) As Integer '... End Function Function Subtract(x As Integer, y As Integer) As Integer '... End Function End Class
これには以下のデメリットが発生します。
- 本来
IMyLogger
だけに依存したいはずなのに、IoCコンテナ(Container
)にも依存してしまっている- 本来なら必要のない別のクラスに依存することになり、依存を減らしたいはずなのに逆に増えてしまっている
- そのクラスが依存しているインターフェース・クラスがコンストラクタのシグネチャから判別がつかない
- コンテナが保持するインターフェース・クラスをすべて利用することが出来てしまうため、不用意に不要なクラスへアクセス出来てしまうため、なんかやばい
なんで、まぁサービスロケーターとして使うのはやめましょうねって感じで。
おわりに
弊社は最近では自動化ツールを作ったりコンソールアプリケーションを作成する機会が多いです。
そんな中、どのみち必要になるから最初からNuGetでぶち込んでおけと思うのが以下の3つです。
今回のでロギングライブラリのもんにょりが消えたので、残るはコマンドラインオプションパーサーになるのですが、今のところしっくりくるのがありません。
なければ作るしかないっぽいのでアレですが、当面はいい感じのを探していこうと思っています。
おわり