xin9le.net

Microsoft の製品/技術が大好きな Microsoft MVP な管理人の技術ブログです。

gRPC / MagicOnion 入門 (12) - ログを出力する

アプリケーション開発においてログの出力は非常に重要です。どこで、どのようなことが起こったのかを知る手がかりになります。gRPC には標準でログを出力するための機構が備わっているので、今回はそれを使ってログ出力をしてみます。

コンソールにログを出力する

とりあえず、最も簡単なコンソール画面へのログ出力をしてみましょう。まず準備として、以下のようにロガーを設定します。

using System;
using Grpc.Core;
using Grpc.Core.Logging;
using MagicOnion.Server;

namespace MagicOnionSample.Service
{
    class Program
    {
        static void Main()
        {
            //--- コンソール画面へログ出力をするように設定
            GrpcEnvironment.SetLogger(new ConsoleLogger());

            //--- いつもの gRPC サーバー起動
            var service = MagicOnionEngine.BuildServerServiceDefinition();
            var port = new ServerPort("localhost", 12345, ServerCredentials.Insecure);
            var server = new Server(){ Services = { service }, Ports = { port } };
            server.Start();
            Console.ReadLine();
        }
    }
}

ConsoleLogger は gRPC にビルトインされているので、すぐに利用することができます。

次にログを出力してみましょう。以下のように Debug / Info / Warning / Error で分類して出力することができます。

using System;
using Grpc.Core;
using MagicOnion;
using MagicOnion.Server;
using MagicOnionSample.ServiceDefinition;
using MessagePack;

namespace MagicOnionSample.Service
{
    public class SampleApi : ServiceBase<ISampleApi>, ISampleApi
    {
        public async UnaryResult<Nil> Sample()
        {
            Console.WriteLine("--------------------");
            GrpcEnvironment.Logger.Debug("Debug");
            GrpcEnvironment.Logger.Info("Info");
            GrpcEnvironment.Logger.Warning("Warning");
            GrpcEnvironment.Logger.Error("Error");

            return Nil.Default;
        }
    }
}

実行すると以下のような出力がされます。標準の ConsoleLogger の出力では、先頭文字が 4 種類のメソッドの頭文字になっていることが分かりますね。

f:id:xin9le:20170906002333p:plain

独自のロガーを利用する

GrpcEnvironment.SetLogger には ILogger インターフェースを実装した型を差し込むことができます。独自のロガーを作成すれば、ロガーの差し替えだけで出力先 / 出力形式を差し替えられるので便利です。ここではその一例として、ファイルに対してログ出力するものを実装してみましょう。例えば以下のようになります。

using System;
using System.IO;
using Grpc.Core.Logging;

namespace MagicOnionSample.Service
{
    public class FileLogger : ILogger
    {
        private TextWriter Writer { get; }

        public FileLogger()
        {
            var desktop = Environment.GetFolderPath(Environment.SpecialFolder.Desktop);
            var path = Path.Combine(desktop, $"{DateTime.Now:yyyy-MM-dd HH-mm-ss}.log");
            this.Writer = TextWriter.Synchronized(new StreamWriter(path));
        }

        #region ILogger implementations
        public ILogger ForType<T>() => this;
        public void Debug(string message) => this.Log("D", message);
        public void Debug(string format, params object[] formatArgs) => this.Debug(string.Format(format, formatArgs));
        public void Info(string message) => this.Log("I", message);
        public void Info(string format, params object[] formatArgs) => this.Info(string.Format(format, formatArgs));
        public void Warning(string message) => this.Log("W", message);
        public void Warning(string format, params object[] formatArgs) => this.Warning(string.Format(format, formatArgs));
        public void Warning(Exception exception, string message) => this.Warning(message + " " + exception);
        public void Error(string message) => this.Log("E", message);
        public void Error(string format, params object[] formatArgs) => this.Error(string.Format(format, formatArgs));
        public void Error(Exception exception, string message) => this.Error(message + " " + exception);
        #endregion

        private void Log(string severity, string message)
        {
            var text = $"{severity} - {DateTime.Now:yyyy/MM/dd HH:mm:ss.ffffff} | {message}";
            this.Writer.WriteLine(text);
        }
    }
}

これでデスクトップに以下のような結果が書き込まれたファイルが出力されます。

D - 2017/09/06 00:40:03.214088 | Attempting to load native library "C:\Users\t.suzuki\documents\visual studio 2017\Projects\MagicOnionSample\MagicOnionSample.Service\bin\Debug\grpc_csharp_ext.x86.dll"
D - 2017/09/06 00:40:03.236148 | gRPC native library loaded successfully.
D - 2017/09/06 00:40:08.379669 | Debug
I - 2017/09/06 00:40:08.379669 | Info
W - 2017/09/06 00:40:08.379669 | Warning
E - 2017/09/06 00:40:08.379669 | Error

複数のロガーをまとめる

GrpcEnvironment.SetLogger の API シグネチャからも分かりますが、gRPC に設定できるロガーはひとつだけとなっています。しかし、実際にはコンソールに出力しつつ BigQuery にもログを飛ばす、などの運用をしたくなると思います。もちろんそのような独自ロガーを作成しても良いですが、「コンソール出力」と「BigQuery への出力」を分離して実装したいというのが人情でしょう。

そういう要求に応えるため、MagicOnion には CompositeLogger が提供されています。以下のように簡単に利用できます。

GrpcEnvironment.SetLogger(new CompositeLogger
(
    new ConsoleLogger(),
    new FileLogger()
));

単機能の独自ロガーを量産しても大丈夫ですね :)