Cy#の河合です。今回、.NET CoreアプリケーションとUnityのために新しく「ZLogger」というロガーを公開しました。非常に高速、かつ、以前に紹介したZStringをバックエンドに持つことにより、文字列整形時のアロケーションをなくしています。主に .NET Core 向けに開発したものですが、Unity(IL2CPPやモバイル環境を含む）でも動くように調整してあります。
特にコンテナ化において、標準出力は重要です。例えばDatadog LogsやStackdriver Loggingは、コンテナの標準出力から直接ログを収集します。Thw Twelve-Factor App – XI. Logsの項でも、標準出力への書き出しが推奨されています。そのような中で、ローカル環境用の装飾過多なログや、低速なConsole.WriteLineで標準出力を扱うのは、あまりにも古い考えだと言えますし、残念ながら今まで .NET Core ではそこを重要視したライブラリは存在しませんでした。
旧来のロギング処理は、多くの無駄が存在しています。
標準的なString.Formatは、値を全てobjectで受け取るためにボクシングが発生し、更にUTF16のStringを新しく生成します。このStringをUTF8でエンコードして、最終的なストリームへと書き込む流れになりますが、ZLoggerの場合はZStringを用いてフォーマット文字列を直接バッファ域にUTF8として書き込み、ConsoleStreamにまとめて流し込みます。プリミティブ型のボクシングも発生せず、非同期で一気に書き込むため、呼び出し側、そしてアプリケーション全体に負荷を与えません。
また、標準出力への最適化のほか、ファイルへの書き込みなどのプロバイダーなど通常のロガーとして期待される内容も標準で用意しているため、様々なところで今すぐ使えます。
ロガーのセットアップはGeneric HostによるConfigureLoggingに従います。そのためMicrosoft.Extensions.Loggingによるフィルタリングなども設定できます。
using ZLogger;
Host.CreateDefaultBuilder()
.ConfigureLogging(logging =>
{
// optional(MS.E.Logging):clear default providers.
logging.ClearProviders();
// optional(MS.E.Logging): default is Info, you can use this or AddFilter to filtering log.
logging.SetMinimumLevel(LogLevel.Debug);
// Add Console Logging.
logging.AddZLoggerConsole();
// Add File Logging.
logging.AddZLoggerFile("fileName.log");
// Add Rolling File Logging.
logging.AddZLoggerRollingFile((dt, x) => $"logs/{dt.ToLocalTime():yyyy-MM-dd}_{x:000}.log", x => x.ToLocalTime().Date, 1024);
// Enable Structured Logging
logging.AddZLoggerConsole(options =>
{
options.EnableStructuredLogging = true;
});
})
public class MyClass
{
readonly ILogger<MyClass> logger;
// get logger from DI.
public class MyClass(ILogger<MyClass> logger)
{
this.logger = logger;
}
public void Foo()
{
// log text.
logger.ZLogDebug("foo{0} bar{1}", 10, 20);
// log text with structure in Structured Logging.
logger.ZLogDebugWithPayload(new { Foo = 10, Bar = 20 }, "foo{0} bar{1}", 10, 20);
}
}
基本的にロガーはDIによって注入されます（LogManager.GetLoggerのような使い方がしたい場合はReadMe#Global LoggerFactoryを参照ください)。LogDebugやLogInformationの代わりに、先頭にZをつけたZLogDebug, ZLogInformationを使うのが基本的な流れです。
標準のLogメソッドは(string format, object[] args)というメソッド定義のため、どうしてもボクシングを避けられません。そのため、独自のジェネリクスで用意した大量のオーバーロードを定義してあります。
// ZLog, ZLogTrace, ZLogDebug, ZLogInformation, ZLogWarning, ZLogError, ZLogCritical and *WithPayload. public static void ZLogDebug(this ILogger logger, string format) public static void ZLogDebug(this ILogger logger, EventId eventId, string format) public static void ZLogDebug(this ILogger logger, Exception? exception, string format) public static void ZLogDebug(this ILogger logger, EventId eventId, Exception? exception, string format) public static void ZLogDebug<T1>(this ILogger logger, string format, T1 arg1) public static void ZLogDebug<T1>(this ILogger logger, EventId eventId, string format, T1 arg1) public static void ZLogDebug<T1>(this ILogger logger, Exception? exception, string format, T1 arg1) public static void ZLogDebug<T1>(this ILogger logger, EventId eventId, Exception? exception, string format, T1 arg1) // T1~T16 public static void ZLogDebug<T1, T2, T3, T4, T5, T6, T7, T8, T9, T10, T11, T12, T13, T14, T15, T16>(this ILogger logger, EventId eventId, Exception? exception, string format, T1 arg1, T2 arg2, T3 arg3, T4 arg4, T5 arg5, T6 arg6, T7 arg7, T8 arg8, T9 arg9, T10 arg10, T11 arg11, T12 arg12, T13 arg13, T14 arg14, T15 arg15, T16 arg16)
標準のLogメソッドと、ZLogメソッドが混在することにより、ミスしてしまう（ZLogメソッドを使うつもりが誤ってLogメソッドを使ってしまう）可能性が非常に高いですが、これは Microsoft.CodeAnalysis.BannedApiAnalyzersを使用することで、コード上で標準Logメソッドを警告/エラー扱いにできます。
このBannedApiAnalyzersを設定することにより、確実にZLoggerを高パフォーマンスで使用できます。
構造化ロギング
ログ管理のクラウドサービス、例えばDatadog LogsやStackdriver Loggingなどは、柔軟なフィルタリングや検索、式を使ったクエリを行えますが、その機能をフルに活かすためにはログが適切にパースされている必要があります。構造化ロギング(Structured Logging, Semantic Logging)は、ログをJSONで送ることにより、特別な後処理をせずログサービスに読み込ませることができます。ZLoggerでは EnableStructuredLogging を有効にすることでテキストメッセージによる出力と、JSON出力を切り替えることができます。また、複数のログプロパイダでそれぞれ切り替えることができるので、コンソール出力はテキストメッセージ、ファイル出力はJSONといった設定も可能です。
logging.AddZLoggerConsole(options =>
{
options.EnableStructuredLogging = true;
});
// In default, output JSON with log information(categoryName, level, timestamp, exception), message and payload(if exists).
// {"CategoryName":"ConsoleApp.Program","LogLevel":"Information","EventId":0,"EventIdName":null,"Timestamp":"2020-04-07T11:53:22.3867872+00:00","Exception":null,"Message":"Registered User: Id = 10, UserName = Mike","Payload":null}
logger.ZLogInformation("Registered User: Id = {0}, UserName = {1}", id, userName);
// {"CategoryName":"ConsoleApp.Program","LogLevel":"Information","EventId":0,"EventIdName":null,"Timestamp":"2020-04-07T11:53:22.3867872+00:00","Exception":null,"Message":"Registered User: Id = 10, UserName = Mike","Payload":{"Id":10,"Name":"Mike"}}
logger.ZLogInformationWithPayload(new UserRegisteredLog { Id = id, Name = userName }, "Registered User: Id = {0}, UserName = {1}", id, userName);
構造化ロギングにおいても、 System.Text.Json の Utf8JsonWriter によるUTF8への直接の書き込み処理や IBufferWriterを活用した透過的なバッファーの受け渡しによって、JSON処理に関連する一切のアロケーションや、余計なコピーの発生によるパフォーマンス低下を徹底的に防いでいます。
Microsoft.Extensions.Loggingへの直接の実装
現在、ほとんどの .NET Core アプリケーションは .NET Generic Hostの上に構築されているため(コンソールアプリケーションでさえも！例えばCy#の開発しているConsoleAppFrameworkは簡単にCLIアプリケーションを.NET Generic Host上で動かせます)、Microsoft.Extensionsによるコンフィグの読み込み、DI、ロガーが標準で動いています。
多くのロガーはそれぞれ別個のフレームワークを持ち、Microsoft.Extensions.Loggingへのブリッジという形で統合を実現していますが、ログ出力の際に2つのフレームワークを通ることはパイプラインが長くなり、性能劣化に繋がります。
Microsoft.Extensions.Loggingはログレベル、フィルタリング、複数の出力先の登録など、十分にフレームワークとしての機能を持っています。よって、独自のロギングフレームワークを作らず、可能な限り直接 Microsoft.Extensions.Logging の上に実装することにより、オーバーヘッドを極限まで減らしています。
また、Microsoft.Extensions.Loggingの出力用のプロバイダーは現状最小限、あるいはAzure依存のものしか提供されていないため、それだけで実用とするのは難しいところがありました。それが他のロギングフレームワークを必要としていた理由ですが、ZLoggerは性能面以外に、Console, File, RollingFile, Streamといった十分なプロバイダーを用意することで、Microsoft.Extensions.Loggingのみでも実用レベルに押し上げてます。
また、初期化/終了処理などが全て .NET Generic Host に統合されているため、ロガーの設定も非常にシンプルで済んでいます。
async Task Main()
{
await Host.CreateDefaultBuilder()
.ConfigureLogging(logging =>
{
logging.ClearProviders();
logging.AddZLoggerConsole();
})
.RunAsync();
}
Unity
UnityにおいてはDebug.Log(中身はDebug.unityLogger -> DebugLogHandler -> Internal_Log)しかない、わけではなくて、一応 ILogger, ILogHandler という抽象層が用意されていますが、非常に貧弱かつ、実装がDebugLogHandlerしか存在しない、かつ、Debug.unityLoggerが差し替え不能なので、ほとんどロギングフレームワークとして機能していないでしょう。
ZLoggerをUnityで使うと、標準に比べて「ファイル出力を含む複数のログプロパイダ」「標準的なログレベルとフィルタリング」「ロガー毎のカテゴリ化」などが利点となります。ファイル出力はモバイルアプリケーションではあまり使い道がないですが、VRなどPCアプリケーションでは存在すると嬉しいのではないでしょうか。
また、ロガーによるカテゴリ付与などは、EditorConsoleProなどの、標準よりも強力なログコンソールでのフィルタリングに非常に役立ちます（例えば[UI], [Battle], [Network]などの分類の付与)。
まとめ
Cy#では現在開発中のアプリケーションにおいて、 .NET Core/MagicOnion で実装されたコンテナ上でホスティングされているリアルタイムサーバーのログを Datadog Logs に標準出力経由で、構造化ログとして送っています。
ロギングは昔からパフォーマンス上のネックになりやすい、かつ、現在でもその流量の多さから扱いに関しては慎重に考慮しなければならない領域でした。ZLoggerは余計な設定もなく、標準状態で最大のパフォーマンスを発揮するように設計されています。この現代的観点から再設計された、新しいロギングライブラリ、是非試してみてください。