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()
));

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

gRPC / MagicOnion 入門 (11) - 通信可能なデータ量を変更する

gRPC でデータを送受信するにあたり、どこまでのサイズが許容されるのか。今回はそのあたりの制限と、その緩和について見ていきます。

既定の通信データ量の制限

gRPC のフレームワークは 1 度の通信で送受信できるデータ容量に制限を設けています。既定では送信/受信ともに 4MB (= 4194304 bytes) となっています。容量を超えるデータを送信すると、例えば以下のような例外が飛んできます。(= Unity で発生したケース)

例外がスローされました: 'Grpc.Core.RpcException' (Assembly-CSharp.dll の中)
OnAnchor.OnError
Grpc.Core.RpcException: Status(StatusCode=InvalidArgument, Detail="Received message larger than max (10347353 vs. 4194304)")
   at UniRx.Stubs.<>c.<.cctor>b__3_1(Exception ex)
   at UniRx.Operators.DoObservable`1.Do.OnError(Exception error)
 
(Filename: C:/buildslave/unity/build/artifacts/generated/Metro/runtime/DebugBindings.gen.cpp Line: 51)

通信データ量制約の緩和

4MB を超えるデータのやりとりはそう多くはないですが、場合によっては超えるときもあるでしょう。そういうときは ChannelOptions で設定をオーバーライドしてあげましょう。以下のような感じで変更します。

//--- サーバー側
var server = new Server(new []
{
    //--- 送信 / 受信それぞれ個別に設定できます
    new ChannelOption(ChannelOptions.MaxReceiveMessageLength, int.MaxValue),
    new ChannelOption(ChannelOptions.MaxSendMessageLength, int.MaxValue)
});

//--- クライアント側
var channel = new Channel("localhost", 12345, ChannelCredentials.Insecure, new []
{
    //--- こっちも同じ
    new ChannelOption(ChannelOptions.MaxReceiveMessageLength, int.MaxValue),
    new ChannelOption(ChannelOptions.MaxSendMessageLength, int.MaxValue),
});

ポイントとしてはサーバー側もクライアント側も両方設定する必要があるということです。それはそうですよね。サーバー側が 4MB 以上のデータを送信できたとしても、クライアント側で受け付けない設定になっていれば意味がありません。各アプリケーションや通信のシナリオに応じて、適切に設定してあげましょう!

gRPC / MagicOnion 入門 (10) - ヘッダーの利用

HTTP/2 をベースとする gRPC にもヘッダーがあり、そこに任意のデータを含めて通信することができます。今回はそんなヘッダーをどうやって利用するのか、その方法について解説します。

ヘッダーにデータを詰めて送信する

ヘッダーは Key-Value 形式となっており、文字列か byte 配列 のいずれかの値を詰めることができます。データは以下のように Metadata 型に格納し、WithHeaders メソッドでヘッダーに追加します。

using System;
using System.Threading.Tasks;
using Grpc.Core;
using MagicOnion.Client;
using MagicOnionSample.ServiceDefinition;

namespace MagicOnionSample.Client
{
    class Program
    {
        static void Main() => MainAsync().Wait();

        static async Task MainAsync()
        {
            var channel = new Channel("localhost", 12345, ChannelCredentials.Insecure);

            //--- ヘッダーに詰めるメタデータを生成
            var metadata = new Metadata();
            metadata.Add("Key", "Value");
            metadata.Add("Key-bin", new byte[]{ 1, 2 });

            /*
            //--- この書き方でも OK
            var metadata = new Metadata()
            {
                new Metadata.Entry("Key", "Value"),
                new Metadata.Entry("Key-bin", new byte[]{ 1, 2 }),
            };
            */

            //--- ヘッダーにメタデータを追加
            var client = MagicOnionClient.Create<ISampleApi>(channel).WithHeaders(metadata);

            //--- あとはいつも通り通信しましょう
            var result = await client.Sample();

            //--- アプリが終了しないように
            Console.ReadLine();
        }
    }
}

サーバー側でヘッダーに格納されたデータを取り出す場合は CallContext.RequestHeaders を利用します。例えば以下のようになります。

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

namespace MagicOnionSample.Service
{
    public class SampleApi : ServiceBase<ISampleApi>, ISampleApi
    {
        public async UnaryResult<Nil> Sample()
        {
            //--- ヘッダーから値を取り出す
            var header = this.Context.CallContext.RequestHeaders;
            var value1 = header.Get("Key").Value;
            var value2 = header.Get("Key-bin").ValueBytes;

            Console.WriteLine(value1);
            Console.WriteLine($"{{{value2[0]}, {value2[1]}}}");

            return Nil.Default;
        }
    }
}

たったこれだけでヘッダーを経由したデータの送受信ができました。簡単ですね!

バイナリデータを送信する場合の注意

ヘッダーに文字列を詰めて送信する場合は特に何も気にしなくて良いのですが、バイナリ (byte 配列) を扱う場合はキー名に -bin の接尾辞を付けるというルールがあるので注意が必要です。-bin なしでキーを設定すると以下のような例外が発生します。

Key for binary valued metadata entry needs to have suffix indicating binary value.

ちなみに -bin という文字列は gRPC のライブラリに Metadata.BinaryHeaderSuffix として定義されているので、それを利用しても OK です。

metadata.Add("Key-bin", new byte[]{ 1, 2 });
metadata.Add($"Key{Metadata.BinaryHeaderSuffix}", new byte[]{ 1, 2 });

ヘッダーの使いどころ

そんなヘッダーの利用タイミングですが、たとえば以下のようなときに便利です。困ったときの最終手段として覚えておくと良さそうです。

  • Client Streaming 通信 / Duplex Streaming 通信における引数の代替*1
  • 例外発生時のエラーメッセージの伝搬 *2
  • すべての通信で利用する ID など *3

*1:この 2 通信では引数を利用できないため、その回避方法として

*2:MagicOnion はエラー詳細の送信にヘッダーを利用

*3:MagicOnion は Connection ID の送信にヘッダーを利用

gRPC / MagicOnion 入門 (9) - 明示的にステータスコードを返す

HTTP/1.1 にステータスコードというレスポンスの意味を表す数値があったように、HTTP/2 をベースとする gRPC にもステータスコードがあります。これまでの解説ではレスポンスとして正常値のみを返していたので、HTTP/1.1 のステータスコードで言うところの 200/OK にあたるものが返っていました。今回はエラーハンドリングなどをした際に利用する、独自のステータスコードを返す方法について見ていきます。

サーバー側でステータスコードを返す

サーバー側からステータスコードを返すのは非常に簡単で、ReturnStatusCode メソッドを利用するだけです。例えば以下のように、エラーが発生したときだけエラーステータスを返します。

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()
        {
            try
            {
                //--- 何かエラーが起こったことにする
                throw new Exception("エラーだよ ☆(ゝω・)vキャピ");
                return Nil.Default;  //--- 正常系
            }
            catch (Exception ex)
            {
                //--- 異常系ではステータスコード + エラー詳細を返す
                return this.ReturnStatusCode<Nil>((int)StatusCode.Internal, ex.Message);
            }
        }
    }
}

正常系の場合、ステータスコードは StatusCode.OK が戻されます。また、サーバー側で不意のエラーが発生した場合は適切にハンドリングされて StatusCode.Unknown が返されます。

public async UnaryResult<Nil> Sample()
    => throw new Exception("エラーだよ ☆(ゝω・)vキャピ");

// Status(StatusCode=Unknown, Detail="Exception was thrown by handler.")

クライアント側でステータスコードを取得する

サーバーから送信されてきたステータスコードをクライアントで取得する場合は、以下のように GetStatus メソッドを呼び出します。

using System;
using System.Threading.Tasks;
using Grpc.Core;
using MagicOnion.Client;
using MagicOnionSample.ServiceDefinition;

namespace MagicOnionSample.Client
{
    class Program
    {
        static void Main() => MainAsync().Wait();

        static async Task MainAsync()
        {
            var channel = new Channel("localhost", 12345, ChannelCredentials.Insecure);
            var client = MagicOnionClient.Create<ISampleApi>(channel);

            //--- 重要 : ヘッダーを取得してからステータスコードを読む
            var call = client.Sample();
            var header = await call.ResponseHeadersAsync;
            var status = call.GetStatus();

            Console.WriteLine(status);
            // Status(StatusCode=Internal, Detail="エラーだよ☆(ゝω・)vキャピ")

            Console.ReadLine();
        }
    }
}

重要なポイントは ResponseHeadersAsyncawait してから GetStatus をする必要があるということです。ResponseHeadersAsync を呼び出すことなしに GetStatus を呼び出すと例外が発生します。また、OK 以外のステータスコードが送られているレスポンスに対して値を読み出そうとしても例外が発生します。

try
{
    var result = await client.Sample();

    //--- 上の書き方は以下のショートカット記法
    //var call = client.Sample();
    //var result = await call.ResponseAsync;
}
catch (Exception ex)
{
    Console.WriteLine(ex.Message);
    // Status(StatusCode=Internal, Detail="エラーだよ☆(ゝω・)vキャピ")
}

ステータスコードの種類

gRPC が提供している定義済みステータスコードは (執筆時点で) 全 17 種類あります。

コード 説明
OK 0 正常終了
Cancelled 1 操作がキャンセルされた
(通常、クライアント側からの要求で)
Unknown 2 不明なエラー
InvalidArgument 3 クライアント側が不適切な引数を与えた
DeadlineExceeded 4 操作完了前に期限切れ
NotFound 5 要求されたものが見つからなかった
AlreadyExists 6 作成しようとしたものが既に存在する
PermissionDenied 7 操作を実行する権限がない
ResourceExhausted 8 リソースが使い果たされている / 容量不足
FailedPrecondition 9 操作が実行可能な状態にないため拒否された
Aborted 10 中止された
OutOfRange 11 有効な範囲を超えて操作しようとした
Unimplemented 12 指定された操作が未実装 / 未サポート
Internal 13 内部的なエラー
Unavailable 14 現在サービスを利用できない
DataLoss 15 回復不能なデータの損失または破損
Unauthenticated 16 有効な認証資格がない

もちろんこれらは定義済みというだけなので、それ以外の独自コードを定義して送信することも可能です。ReturnStatusCode メソッドの引数が int になっているのはそのためです。

また、gRPC のフレームワークが返す可能性のあるステータスコードも以下にまとまっています。もし見たことのないステータスコードを目撃したら、gRPC 自体が原因かどうかを調べるために使ってみてください。

gRPC / MagicOnion 入門 (8) - 独自型を送受信する

ここまで gRPC / MagicOnion を基本的な通信方法について見てきました。しかし、送受信に利用した型はすべて Primitive 型ばかりでした。独自に定義した型で通信したいと思うのは当然!ということで、今回は独自型でサーバー / クライアント間のやり取りをする方法について解説していきます。

MessagePack for C# のルールに従う

MagicOnion で通信されるデータのシリアライズには MessagePack for C# が利用されています。これにより MessagePack for C# が提供する超高速なシリアライズの恩恵を受けられるだけでなく IDL も不要になるため、.NETer が gRPC を使う環境としては最高に快適なものとなっています。

MagicOnion のシリアライザとして MessagePack for C# が利用されているということは、独自型をやり取りする場合も MessagePack for C# のルールに則るということになります。

独自型を定義する

通信でやりとりする独自型はサーバーとクライアントで型が共有されなければなりません。なので、サービス定義のプロジェクト内 (もしくはそれに類するサーバーとクライアントで共有可能なプロジェクト) に型を定義します。例えば以下のようにします。

using MessagePack;

namespace MagicOnionSample.ServiceDefinition
{
    //--- MessagePack for C# によるシリアライズ対象であることマーク
    [MessagePackObject]
    public struct Vector2
    {
        //--- バイナリのレイアウトの順番を設定
        [Key(0)]
        public float X { get; }

        [Key(1)]
        public float Y { get; }

        //--- デシリアライズに使うコンストラクタであることをマーク
        //--- ※ルールに沿っていれば必須ではない
        [SerializationConstructor]
        public Vector2(float x, float y)
        {
            this.X = x;
            this.Y = y;
        }
    }
}

MessagePack for C# のルールに則った記述をソラでするのはなかなかに厳しいと思います。そんなときに便利なのが MessagePackAnalyzer です。サービス定義のプロジェクトに NuGet からアナライザーを取得して追加しておきましょう。

PM> Install-Package MessagePackAnalyzer

MessagePack for C# に関する詳細は README を参照ください。

独自型を利用して通信する

独自型の定義ができたので、これを利用して実装してみましょう。例えば以下のようにすれば OK です。

using MagicOnion;
using MessagePack;

namespace MagicOnionSample.ServiceDefinition
{
    public interface ISampleApi : IService<ISampleApi>
    {
        //--- 独自型を使ったサービス定義
        UnaryResult<Nil> Sample(Vector2 point);
    }
}
using System;
using MagicOnion;
using MagicOnion.Server;
using MagicOnionSample.ServiceDefinition;
using MessagePack;

namespace MagicOnionSample.Service
{
    public class SampleApi : ServiceBase<ISampleApi>, ISampleApi
    {
        //--- そのまま受け取れます
        public async UnaryResult<Nil> Sample(Vector2 point)
        {
            Console.WriteLine($"(x, y) = ({point.X}, {point.Y})");
            return Nil.Default;  //--- 独自型を返せます
        }
    }
}
using System;
using System.Threading.Tasks;
using Grpc.Core;
using MagicOnion.Client;
using MagicOnionSample.ServiceDefinition;

namespace MagicOnionSample.Client
{
    class Program
    {
        static void Main() => MainAsync().Wait();

        static async Task MainAsync()
        {
            var channel = new Channel("localhost", 12345, ChannelCredentials.Insecure);
            var client = MagicOnionClient.Create<ISampleApi>(channel);

            //--- そのまま送受信できます
            var point = new Vector2(3, 5);
            var result = await client.Sample(point);
            Console.WriteLine(result.GetType().FullName);

            Console.ReadLine();
        }
    }
}

Nil という初出の型がありますが、これは MessagePack for C# に定義されている「何もない」を表現する型です。Rx を知っている方であれば Unit 型と同じようなものと言えば良いでしょうか。実行結果は以下のようになります。

f:id:xin9le:20170612013336p:plain

まとめ

MessagePack for C# のルールに則って独自型を定義するだけで難なくサーバー/クライアント間でやりとりすることができるようになりました。今回は説明していませんが、独自型のネストやコレクションにも対応しています。結局のところ gRPC は HTTP/2 上でバイナリデータを送受信しているだけなので、MessagePack for C# でシリアライズ / デシリアライズできるものであれば何だって通信できます。