LoggerをDIする事についての議論

この記事の目的

Loggerを様々なクラスで使用するにあたり、ASP.NET MVC Coreでは、規定でDIを用いてILoggerインタフェースにLoggerを注入します。

しかしこれまで多くのシステムでは、Loggerクラスの静的メソッドを用いてLoggerインスタンスを取得し、以下のように使っていました。

static readonly log4net.Ilog _logger = log4net.LogManager.GetLogger("ErrorLog");

上記のコードがどのレベルにあるか（クラスレベルか、システムグローバルか）はさておき、各クラスからはなんらかのグローバル変数かクラスの静的メンバを直接参照していたわけです。

しかし、クラスを特定のグローバルな何かに依存させるやり方は、そのクラスの可搬性を下げ、テストもしにくくしてしまいます。

その問題を解決する為にDIが導入されたのですが、LoggerをDIすることについては様々な議論があります。

私自身も、「Loggerをシステム全体にDIして回ることが、果たしてそのコストに見合うだけの利点をもたらしてくれるのだろうか？ 逆に、グローバル変数に依存させることで、どれだけの問題が発生しているのだろうか？」という疑念を持っています。

この件に関して、とても参考になる記事がありました。

9年前のstackoverflowの記事ですが、今でも有用だと思いますので要約して残したいと思います。
https://stackoverflow.com/questions/12591955/should-logging-infrastructure-be-injected-when-using-ioc-di-if-logging-facade-is

尚、上記の記事に対する私自身の現在の考えは、記事の最後にまとめましたので、そちらだけ読んで頂いても結構です。

質問

Log4NetのLoggingファサードを使っており、それをDIコンテナを使って生成、注入しています。その為、ログ出力が必要な全てのクラスが、追加のコンストラクタ・パラメータを必要としています。

// DIする場合のやり方
public class MyController : BaseController
{
    private readonly ILog _logger;

    public MyController(ILog logger)
    {
        _logger = logger;
    }

    public IList<Customers> Get()
    {
        _logger.Debug("I am injected via constructor using some IoC!");
    }
}

// ロガーを直接使用するやり方
public class MyController : BaseController
{
    private static readonly ILog Logger = LogManager.GetCurrentClassLogger();

    public IList<Customers> Get()
    {
        Logger.Debug("Done! I can use it!");
    }
}

Loggingファサードを使っている場合、DIは必須なのでしょうか？
コンストラクタにLoggerを指定することで、クラスの依存関係を明示的に公開することは優れたアーキテクチャーであることは理解しています。
しかし、このファサードの場合、次の事が当てはまると思います。

• このロギングフレームワークはいつでも「退避」させることができます。
• 私の考えでは、このクラスは実際にはLoggerに依存していません。ロギングが構成されていなければ、それは何もしません。

みなさんはどう思いますか？
Loggingファサードを注入するのはやりすぎですか？
DIの一般論ではなく、ロギングについて主に興味があります。

ロギングにDIは不要論

ロギングは単なるインフラストラクチャです。それを注入するのはやり過ぎです。私は個人的に抽象化レイヤーさえ使用していません。ライブラリが直接提供する静的クラスを使用します。私の動機は、現在のプロジェクトでログライブラリを切り替える可能性は低いということです（ただし、次のプロジェクトに切り替える可能性があります）。

反論

A「（Loggingファサードの直接使用は）設定ファイルに依存性を持ち込んでしまい、自動テストを妨げる為、DIされるべきだと考えます」

回答者「メジャーなロギングライブラリの多くは設定がなければ何も行いません。単にログ出力をしないだけです。なのであなたは間違っています」

A「その通りです。その点を忘れていました。でもコードをクリーンに保つのは良いことです！」

ロギングにもDIは必要論

ロギングシステムのIoCがやり過ぎであるという考えは近視眼的です。

ロギングは、アプリケーション開発者が他のシステム（イベントログ、フラットファイル、データベースなど）と通信できるメカニズムであり、これらはそれぞれ、アプリケーションが依存する外部リソースになります。

ユニットテストされたコードが特定のロガーにロックされている場合、コンポーネントのログをユニットテストするにはどうすればよいですか？ 分散システムは、ファイルシステム上のフラットファイルではなく、ソースを一元化するためにログを記録するロガーを使用することがよくあります。

私にとって、ロガーを挿入することは、データベース接続APIまたは外部Webサービスを挿入することと同じです。これはアプリケーションが必要とするリソースであるため、注入する必要があります。これにより、コンポーネントでのリソースの使用状況をテストできます。ロギング受信者とは無関係にコンポーネントの出力をテストするために、前述の依存関係をモックする機能は、強力な単体テストに不可欠です。

そして、IoCコンテナがそのような注入を容易く行うことを考えると、ロガーを注入するためにIoCを使用しないことは、そうすることよりも有効なアプローチではないように思われます。

反論（というか補足）

A「ここで考慮しなければならないのは、それがドメインかインフラストラクチャか、です。高レベルの設計でログが表示されるのなら、それはドメインの問題です。インタフェースの一部を形成するため、テストが必要になるでしょう。ドメインのコードはテストされ、DIされるべきです」

B「"それが本当のロギングかどうか"を議論する前に、もう少し微妙な語彙が必要かもしれません。例えば私の経験では、診断ログとテレメトリ（訳注：テレメトリとは、システム改善の為に取る利用状況データのこと））（ドメインレベルではない為、注入されない傾向があります）、および監査ロギング（ドメインレベルで注入される傾向があります）に遭遇しました。従来のロギングフレームワークは診断ロギングを対象としており、ロギング操作が失敗したときに例外をスローするなどの動作のサポートを非常に限られています。」

別の視点による指摘

（「Dependency Injection Principles, Practices, and Patterns」の著者の一人、Steven van Deursen による回答）

システムの多くのクラスでログを記録する必要がある場合は、設計に問題があります。ロギングは横断的関心事であり、ロギングのような横断的関心事でクラスを乱雑にすべきではないため、ロギングが多すぎるか、単一責任原則に違反しています。

以前書いたこの回答が参考になるでしょう。
https://stackoverflow.com/questions/9892137/windsor-pulling-transient-objects-from-the-container/9915056#9915056

上記の回答の内容

一般に、ILoggerのインスタンスをほとんどのサービスに注入している場合、次の2つのことを自問する必要があります。

1. ログに記録しすぎていませんか？
2. SOLIDの原則に違反していませんか？

1.ログに記録しすぎていませんか

次のようなコードがたくさんある場合、あなたはロギングのやりすぎです:

try
{
   // some operations here.
}
catch (Exception ex)
{
    this.logger.Log(ex);
    throw;
}

このようなコードを書くことは、エラー情報を失うことへの懸念から来ています。ただし、これらの種類のtry-catchブロックをあちこちに複製しても効果はありません。さらに悪いことに、開発者がログを記録し、最後のthrowステートメントを削除して続行するのをよく目にします。

try
{
   // some operations here.
}
catch (Exception ex)
{
    this.logger.Log(ex); // <!-- No more throw. Execution will continue.
}

ほとんどの場合、これは悪い考えです（そして、古いVBのON ERROR RESUME NEXT動作のようなにおいがします）。ほとんどの場合、安全であるかどうかを判断するのに十分な情報がないためです。多くの場合、コードにバグがあるか、データベースなどの外部リソースに問題があり、操作が失敗します。続行するということは、操作が成功したのに成功しなかったという考えをユーザーがしばしば得ることを意味します。自問してみてください。さらに悪いことに、何か問題が発生したことを示す一般的なエラーメッセージを表示して再試行するように求めたり、エラーを黙ってスキップしてユーザーにリクエストが正常に処理されたと思わせたりしますか？

2週間後に注文が発送されなかったことをユーザーが知った場合、ユーザーがどのように感じるかを考えてください。あなたはおそらく顧客を失うでしょう。さらに悪いことに、患者のMRSA登録は黙って失敗し、その患者は看護によって隔離されず、他の患者の汚染を引き起こし、高額な費用やおそらく死に至ることさえあります。

これらの種類のtry-catch-log行のほとんどは削除されるべきであり、あなたは単純にこの例外を呼び出しスタックにバブルアップさせる（訳注：つまり、catchも何もしないで呼び出し元に任せる、ということと思われます）だけにすべきです。

これは、ログに記録しなくても良いということでしょうか？ あなたは絶対にすべきです！ ただし、可能であれば、アプリケーションの上部に1つのtry-catchブロックを定義します。ASP.NETを使用すると、Application_Errorイベントを実装したり、HttpModuleを登録したり、ログを記録するカスタムエラーページを登録または定義したりできます。Win Formsの場合、ソリューションは異なりますが、概念は同じです。1つの最上位のcatch-allを定義します。

ただし、特定の種類の例外をキャッチしてログに記録したい場合もあります。私が過去に取り組んだシステムでは、ビジネスレイヤーがValidationExceptionsをスローし、プレゼンテーションレイヤーによってキャッチされます。これらの例外には、ユーザーに表示するための検証情報が含まれていました。これらの例外はプレゼンテーション層でキャッチされて処理されるため、アプリケーションの最上部にバブルアップすることはなく、アプリケーションのcatch-allコードに含まれることもありませんでした。それでも、ユーザーが無効な情報を入力した頻度と、正当な理由で検証がトリガーされたかどうかを確認するために、この情報をログに記録したかったのです。したがって、これはエラーログではありませんでした。ただロギングです。私はこれを行うために次のコードを書きました：

try
{
   // some operations here.
}
catch (ValidationException ex)
{
    this.logger.Log(ex);
    throw;
}

おなじみですか？はい、前のコードスニペットとまったく同じように見えますが、ValidationException例外をキャッチしただけであるという違いがあります。ただし、このスニペットを見ただけではわからない別の違いがありました。そのコードを含むアプリケーション内の場所は1つだけでした！それはデコレータでした。これはあなたが自分自身に尋ねるべき次の質問を導きます：

2. SOLIDの原則に違反していませんか？

ロギング、監査、セキュリティなどは、横断的関心事（または側面）と呼ばれます。これらは、アプリケーションの多くの部分を横断でき、システム内の多くのクラスに適用する必要があるため、Cross-Cutting-Concern（横断的関心事）又はアスペクトと呼ばれます。ただし、システム内の多くのクラスで使用するコードを記述している場合は、SOLIDの原則に違反している可能性があります。たとえば、次の例を見てください。

public void MoveCustomer(int customerId, Address newAddress)
{
    var watch = Stopwatch.StartNew();

    // Real operation
    
    this.logger.Log("MoveCustomer executed in " +
        watch.ElapsedMiliseconds + " ms.");
}

ここでは、MoveCustomer操作の実行にかかる時間を測定し、その情報をログに記録します。このシステム内の他の操作でも、これと同じ横断的関心事が必要になる可能性が非常に高くなります。あなたは、ShipOrder、CancelOrder、CancelShipping、および他の使用例のために、このようなコードを追加し始め、これが多くのコードの重複をもたらし、最終的にメンテナンスの悪夢へと至ります（私はそこにいました）。

このコードの問題は、SOLIDの原則の違反にまでさかのぼることができます。SOLIDの原則は、柔軟で保守可能な（オブジェクト指向の）ソフトウェアを定義するのに役立つオブジェクト指向の設計原則のセットです。このMoveCustomerの例は、これらのルールの少なくとも2つに違反しています。

1. 単一責任の原則（SRP）- クラスは単一の責任を持つべきです。MoveCustomerメソッドを持つクラスにはコアビジネスロジックが含まれているだけでなく、操作の実行にかかる時間の測定も含まれます。言い換えれば、それは複数の責任を負っています。

2. オープン・クローズの原則（OCP）- コードベース全体で大幅な変更を加える必要がないようにするアプリケーション設計を規定しています。または、OCPの語彙では、クラスは拡張のために開いている必要がありますが、変更のために閉じている必要があります。 MoveCustomerユースケースに例外処理（3番目の責任）を追加する必要がある場合は、（再び）MoveCustomerメソッドを変更する必要があります。ただし、MoveCustomerメソッドだけでなく、他の多くのメソッドも変更する必要があります。これらのメソッドは通常、同じ例外処理を必要とし、これを大幅に変更します。

この問題の解決策は、ロギングを独自のクラスに抽出し、そのクラスが元のクラスをラップできるようにすることです。

// The real thing
public class MoveCustomerService : IMoveCustomerService
{
    public virtual void MoveCustomer(int customerId, Address newAddress)
    {
        // Real operation
    }
}

// The decorator
public class MeasuringMoveCustomerDecorator : IMoveCustomerService
{
    private readonly IMoveCustomerService decorated;
    private readonly ILogger logger;

    public MeasuringMoveCustomerDecorator(
        IMoveCustomerService decorated, ILogger logger)
    {
        this.decorated = decorated;
        this.logger = logger;
    }

    public void MoveCustomer(int customerId, Address newAddress)
    {
        var watch = Stopwatch.StartNew();

        this.decorated.MoveCustomer(customerId, newAddress);
    
        this.logger.Log("MoveCustomer executed in " +
            watch.ElapsedMiliseconds + " ms.");
    }
}

デコレータを実際のインスタンスにラップすることで、システムの他の部分を変更することなく、この測定動作をクラスに追加できるようになりました。

IMoveCustomerService service =
    new MeasuringMoveCustomerDecorator(
        new MoveCustomerService(),
        new DatabaseLogger());

ただし、前の例では、問題の一部（SRP部分のみ）を解決しただけです。上記のようにコードを書くとき、あなたはシステム内のすべての操作に対して個別のデコレータを定義する必要がありますし、それは MeasuringShipOrderDecorator、MeasuringCancelOrderDecorator、MeasuringCancelShippingDecorator、のようなデコレータになってしまうでしょう。これもまた多くの重複コード（OCP原則の違反）につながり、システム内のすべての操作に対してコードを記述する必要があります。ここで欠落しているのは、システムのユースケースに関する一般的な抽象化です。

欠けているのはICommandHandler<TCommand>インターフェースです。

このインターフェースを定義しましょう：

public interface ICommandHandler<TCommand>
{
    void Execute(TCommand command);
}

そして、MoveCustomerメソッドのメソッド引数を、MoveCustomerCommandという名前の（パラメータオブジェクト）クラスに格納しましょう：

public class MoveCustomerCommand
{
    public int CustomerId { get; set; }
    public Address NewAddress { get; set; }
}

そして、MoveCustomerメソッドの動作をICommandHandler<MoveCustomerCommand>を実装するクラスに実装しましょう：

public class MoveCustomerCommandHandler : ICommandHandler<MoveCustomerCommand>
{
    public void Execute(MoveCustomerCommand command)
    {
        int customerId = command.CustomerId;
        Address newAddress = command.NewAddress;
        // Real operation
    }
}

これは最初は奇妙に見えるかもしれませんが、ユースケースの一般的な抽象化ができたので、デコレータを次のように書き直すことができます。

public class MeasuringCommandHandlerDecorator<TCommand>
    : ICommandHandler<TCommand>
{
    private ILogger logger;
    private ICommandHandler<TCommand> decorated;

    public MeasuringCommandHandlerDecorator(
        ILogger logger,
        ICommandHandler<TCommand> decorated)
    {
        this.decorated = decorated;
        this.logger = logger;
    }

    public void Execute(TCommand command)
    {
        var watch = Stopwatch.StartNew();

        this.decorated.Execute(command);
    
        this.logger.Log(typeof(TCommand).Name + " executed in " +
            watch.ElapsedMiliseconds + " ms.");
    }
}

この新しいMeasuringCommandHandlerDecorator<T>はMeasuringMoveCustomerDecoratorによく似ていますが、このクラスはシステム内のすべての*コマンドハンドラーで再利用できます。

ICommandHandler<MoveCustomerCommand> handler1 =
    new MeasuringCommandHandlerDecorator<MoveCustomerCommand>(
        new MoveCustomerCommandHandler(),
        new DatabaseLogger());

ICommandHandler<ShipOrderCommand> handler2 =
    new MeasuringCommandHandlerDecorator<ShipOrderCommand>(
        new ShipOrderCommandHandler(),
        new DatabaseLogger());

このようにして、システムに横断的関心事を追加することがはるかに簡単になります。作成したコマンドハンドラーをシステム内の適切なコマンドハンドラーでラップできる便利なメソッドをコンポジションルートに作成するのは非常に簡単です。例えば：

private static ICommandHandler<T> Decorate<T>(ICommandHandler<T> decoratee)
{
    return
        new MeasuringCommandHandlerDecorator<T>(
            new DatabaseLogger(),
            new ValidationCommandHandlerDecorator<T>(
                new ValidationProvider(),
                new AuthorizationCommandHandlerDecorator<T>(
                    new AuthorizationChecker(
                        new AspNetUserProvider()),
                    new TransactionCommandHandlerDecorator<T>(
                        decoratee))));
}

この方法は次のように使用できます。

ICommandHandler<MoveCustomerCommand> handler1 = 
    Decorate(new MoveCustomerCommandHandler());

ICommandHandler<ShipOrderCommand> handler2 =
    Decorate(new ShipOrderCommandHandler());

ただし、アプリケーションが成長し始めた場合、DIコンテナーは自動登録をサポートできるため、これをDIコンテナーでブートストラップすると便利な場合があります。これにより、システムに追加する新しいコマンド/ハンドラーのペアごとにコンポジションルートを変更する必要がなくなります。

.NET用の最新の成熟したDIコンテナのほとんどは、デコレータをかなり適切にサポートしています。特にAutofac（例）とSimple Injector（例）を使用すると、オープンジェネリックデコレータを簡単に登録できます。

一方、UnityとCastleには、動的インターセプション機能があります（Autofacと同様）。動的インターセプションはデコレーターと多くの共通点がありますが、内部で動的プロキシ生成を使用します。これは一般的なデコレータを使用するよりも柔軟性がありますが、保守性に関しては代償を払う必要があります。これは、型の安全性が失われることが多く、インターセプタは常にインターセプトライブラリに依存するように強制するのに対し、デコレータはタイプセーフであり、外部ライブラリに依存せずに記述されます。

私はこれらのタイプの設計を10年以上使用しており、それなしでアプリケーションを設計することは考えられません。私はこれらの設計について広範囲に書いてきましたが、最近では、依存性注入の原則、実践、およびパターンと呼ばれる本を共著しました。この本では、このSOLIDプログラミングスタイルと上記の設計についてさらに詳しく説明しています（第10章を参照）。

上記の回答に対する反論

A 「あなたの意見自体には同意します。しかし、ロギングに対してその方法を取るには、（DIに加えて）デコレータを用意して実装する必要があります。これは、ロギングの為だけに実装する必要がある別の抽象化になります。本当にそれだけの価値があるのでしょうか？ 私がこの議論を見ている限り、意見は主に、ロギングが「必須」の依存関係であると考える派と、使用できるインフラストラクチャ機能であると考える派に分かれています。控えめに言っても興味深い議論です。」

回答者「それだけの価値があるかどうかはあなた次第です。ただ、既に同様のアーキテクチャを実践している場合、横断的関心事としてロギングを追加するのは簡単です。また、このようなSOLIDデザインが気に入らない場合は、いつでも（訳注：AutoFacの機能のような）インターセプトを使用して、ロギングインターセプターでサービスをデコレートできることを忘れないでください。これにより、サービスに汎用インタフェースを使用する必要がなくなります。」

A「私はSOLIDが好きで、練習するようにしていますが、そのために常にCQRS（コマンドクエリ責務分離）やその同様のコマンドパターンを使用する傾向はありません。あなたはインターセプター/フィルターについて良い点を述べています。他のコメントで私が述べたように、未処理の例外をログに記録する為にWeb APiフィルターを利用し、コントローラーのアクションにtry/catch(Exception e) {log (e);}ロジックが散らばらないようにしています。」

回答者「これらのパターンは、SOLIDの原則を適用した結果にすぎません。これらのパターンは、CQRSを練習していなくても適用できます。それが私のやり方です。構築するすべてのアプリケーションにこのパターンを使用しますが、CQRSを実践したことはありません。このコマンドモデルは、新しい可能性への扉を開きます。「高いメンテナンス性を持つWCFサービスの書き方についての記事」の事例をご覧ください。もう少し作業が必要になりますが、Web APiサービスでも同じことができます。私はこれを実践して、それについての記事も書くことを計画しました。

B「同意しません。作者は"ロギングを実行したい全てのクラスで"とは言いましたが、"ほぼ全てのクラスでロギングを実行したい"ではありません」

この記事を書いた人のまとめ

stackoverflowの各意見はいずれも非常に説得力があるもので、単体で見るとそれぞれに納得してしまうような内容です。

その中でもいくつか心に残ったものがありましたので以下に短くまとめます。

ロガーの多くは何も設定しなければ何もしないので、依存しているというほどでもない

ロガーのDLLに依存してしまっている事実は避けられないので、設定が必須でなければ依存していないというわけでもないとは思います。

ただ、テストのしやすさを考えた時、確かに、ロガーに依存していたからといって問題になるようなケースはほとんどない気はします。

ログには種類があり、それによってアプローチも異なる

• 診断ログとテレメトリログは、ビジネスドメインには属していない為、DIされない傾向にある。
• 監査ログはビジネスドメインに属している為、ログ自体のテストが必要で、DIされる傾向にある。

ログ種類	ドメイン	DI	説明
診断ログ	×	されない傾向	主にサポート用に、トラブルシューティングの目的で使用するログ。
テレメトリ・ログ	×	されない傾向	ユーザーの利用状況を記録し、システムの改善につなげる為のログ。
監査ログ	〇	される傾向	「いつ」「だれが」「何をしたか」を監視する為のログ。
監査ログに関しては、DBに出力しているケースも多そうです。その場合は確かにDIが必要そうです。

それ以外についてはDIにこだわる必要はなさそうです。

ログを出力する箇所が多すぎる場合はそれを見直す必要がある

その代わりに、ログを出力すべき箇所で適切な例外をスローするか、例外が発生した時に単に処理を中断するのであれば、発生した例外をいちいちキャッチしないようにして、「呼び出しの根本」でキャッチして一括でログを出力するようにします。

この場合の「呼び出しの根本」とは、ベースコントローラのOnExceptionメソッドだったり、HttpModuleの登録だったり、MVCフレームワークが呼び出すカスタムエラーページだったりします。

そもそもの問題が「LoggerをDIしようとすると、システムのいろんな箇所にDIしなくてはならなくなって大変すぎる。コストに見合わない」というものだったので、この方法を取れるのであれば、DIすることに弊害はなくなります。

ただ、ログの種類を考えた時、エラーログはそれでよいですが、それ以外のテレメトリ・ログ等の、正常処理の範囲内で出力されるログについてはこれでは対応できません。

また、「ログを出力する箇所が大幅に減る」のであれば、逆に言えば、クラスメンバ呼び出しによるグローバルへのロック・インが行われても、問題になる範囲を極小化できる、ということでもあります。

デコレーターパターンによる関心の分離

診断ログやテレメトリログの場合、ロガーをDIしたとしても、ロギングの処理自体が対象となるクラスの責務に本来関係ないものなので、単一責任の原則に反する、という話。

端的に言えば、「DIしようがしまいが、ロギング処理はクラスを汚す」ということです。

ただ、その解決策として提示されるデコレーターパターンの実装は、反論にもあったように「利点は分かるが、正直ロギングの為だけにここまではやってられない」というものでした。

調べてみると、RealProxyを使ってログ出力を分離した結果、失敗だったという経験を公開して下さっている方もいます。

ASP.NET MVCやWeb APIに限れば、コントローラーのアクションメソッドに対しては、ベースコントローラーのOnExecutingイベントや、アクションフィルタによる関心の分離が可能です。

もしそれで対応できるならそれも良いかと思いました。

個人的には、ログ出力のような横断的関心事を分離する為の機能を、プログラミング言語レベルで用意してくれると楽な気がします（例：Pythonの関数デコレータのようなもの）。PostSharpという有料ツールがその機能を提供してくれるようなのですが、標準機能としてほしいものです。

結論

今のところの結論は「DIにこだわらず、コストが高そうならクラスメンバを直接参照する」となります。詳細は以下の通りです。

• 可能な限り個々のクラスでのログ出力をやめて一か所で集中管理できるようにする（try-catch内でのログ出力の廃止など）。

• その上で、DIするコストが低そうならばDIする。但しこだわらない。

• コストが高そうならばDIせず、クラスメンバの参照で解決する。但しその場合でも、インタフェースを経由する。

static readonly log4net.ILog _logger = log4net.LogManager.GetLogger("ErrorLog");

上記ではlog4net.ILog を使っているが、.NET標準のILogger経由で使う方法もあるので、可能ならそうする。

• ProxyやDecoratorを使った関心の分離には手を出さない。

皆様のご意見もありましたらコメント頂ければ幸いです。