ETW/EventSource によるロギングを試してみる
最近、以下の記事を拝見しました。
neue cc - EtwStream - ETW/EventSourceのRx化 + ビューアーとしてのLINQPad統合
正直、EtwやEventSourceというものに馴染みが無かったのですが、これからは必須の技術となりそうですね。
さて、EventSourceですが、いきなり構造化ログってのもかなりダルいので、まずは非構造化ログをEventSourceで実現するところから初めてみましょう。
という事で、前回の記事で書いた、ScheduledNotifierをベースとした自作のLogger、LogMessageNotifierをEventSourceに置き換えることから初めてみたいと思います。
LogMessageNotifierをEventSourceに変更する
今回は、Logging用のEventSourceに 冒頭の記事の中で掲載されていたLoggerEventSource クラスのコードをそのまま利用させて頂く事とします。
LoggerEventSourceクラスのメソッドをそのまま呼び出しても良いのですが、既存のコードでは、Model側はILoggerインターフェースを通じてLogの書き込みを行っていました。
ひとまずはこの部分は変えずに、LoggerEventSource をILoggger でラップすることで対応します。
using ReactiveBingViewer.Diagnostics; using System; namespace ReactiveBingViewer.Notifiers { /// <summary> /// Logメッセージ通知オブジェクト /// </summary> public class EventSourceLogger : ILogger { public LoggerEventSource EventSource { get; private set; } public EventSourceLogger(LoggerEventSource eventSource =null) { EventSource = eventSource?? LoggerEventSource.Log; } public void Trace(string message) => EventSource.Verbose(message); public void Debug(string message) => EventSource.Debug(message); public void Info(string message) => EventSource.Informational(message); public void Warn(string message) => EventSource.Warning(message); public void Error(string message) => EventSource.Error(message); public void Fatal(string message) => EventSource.Critical(message); public void Trace(string message, Exception e) { Trace(message); LogException(e); } public void Debug(string message, Exception e) { Debug(message); LogException(e); } public void Info(string message, Exception e) { Info(message); LogException(e); } public void Warn(string message, Exception e) { Warn(message); LogException(e); } public void Error(string message, Exception e) { Error(message); LogException(e); } public void Fatal(string message, Exception e) { Fatal(message); LogException(e); } private void LogException(Exception e) { EventSource.Exception(e.GetType().FullName, e.StackTrace.ToString(), e.Message); } } }
ILoggerをそのまま温存したので Model内でのlogの書き込み部分は変更する必要がありません。
後は、ViewModel のコンストラクタで行っている ReactiveProperty を初期化している部分をEventSourceの型に合わせてほんの少し修正するだけで済みそうです。
public class MainWindowViewModel { //private LogMessageNotifier logger = new LogMessageNotifier(); private EventSourceLogger logger = new EventSourceLogger(); public MainWindowViewModel() { //Modelのコンストラクタに logger を渡す webImageStore = new WebImageStore(App.BingApiAccountKey, App.VisionApiSubscriptionKey, logger).AddTo(disposables); var logListner = EtwStream.ObservableEventListener.FromEventSource(logger.EventSource); ////Logファイルに書き出し System.Diagnostics.Trace.Listeners.Add(new System.Diagnostics.TextWriterTraceListener("log.txt")); //logger.Subscribe(log => logListner.Subscribe(log => { System.Diagnostics.Trace.WriteLine(log); System.Diagnostics.Trace.Flush(); }).AddTo(disposables); ////Infoレベルのログはステータスバーに表示 //StatusMessage = logger.Where(x => x.Level == LogLevel.Info) // .Select(x => x.Message) // .ToReadOnlyReactiveProperty(); StatusMessage = logListner.Where(x => x.Level == System.Diagnostics.Tracing.EventLevel.Informational) .Select(x => x.Payload.First().ToString()) .ToReadOnlyReactiveProperty(); ////Warn レベル以上 は エラーリストに表示 ClearErrorLogsCommand = new ReactiveCommand(); //リストクリア用 //ErrorLogs = logger // .Where(x => x.Level >= LogLevel.Warn) // .ToReadOnlyReactiveCollection(ClearErrorLogsCommand.ToUnit()); ErrorLogs = logListner.Where(x => (int)x.Level <= (int)System.Diagnostics.Tracing.EventLevel.Warning) .Select(x=>$"[{x.Level}]{x.Payload[0]} ({x.Payload[2]})") .ToReadOnlyReactiveCollection(ClearErrorLogsCommand.ToUnit()); ////エラーリスト表示切替。 ErrorLogs にアイテムがある場合のみ表示する ErrorLogsVisibility = ErrorLogs .CollectionChangedAsObservable() .Select(_ => (ErrorLogs.Count > 0) ? Visibility.Visible : Visibility.Collapsed) .ToReactiveProperty(Visibility.Collapsed); } }
これで実行してみます。
おお、ちゃんと動きました。
EtwStream で(超簡易版)Etwビューアを作ってみる
後は、EventSourceとしたことでEtwStream を使えばプロセス外からも参照できるはず。早速LINQPadで...
と思ったのですが無償版ではEtwStream.LingPad をNuGetできないのですね。
幸い、ベースライブラリである EtwStream.Core は 通常の.Netプロジェクトに入れられるようですので、これを利用して簡易ビューアを作ってみたいと思います。
- WPFアプリケーションで作ります。
- NuGetでEtwStream とReactiveProperty をインストールします。
PM> Install-Package EtwStream
PM> Install-Package ReactiveProperty
- ViewModel を定義します。
ObservableEventListener.FromTraceEvent() で 取得したIObservable<TraceEvent>
をReactiveCollection に変換します。
using EtwStream; using Reactive.Bindings; using System.Linq; using System.Reactive.Linq; namespace EtwStreamViewer { public class MainWindowViewModel { public ReadOnlyReactiveCollection<string> LogEvents { private set; get; } public MainWindowViewModel() { LogEvents = ObservableEventListener.FromTraceEvent("LoggerEventSource") .Select(x =>$"[{x.TimeStamp}][{x.Level}]: {x.FormattedMessage}" ) .ToReadOnlyReactiveCollection(); } } }
- XAML を定義します。
WindowにListBoxを追加して、ReactiveCollection をバインドします。
<Window x:Class="EtwStreamViewer.MainWindow" xmlns="http://schemas.microsoft.com/winfx/2006/xaml/presentation" xmlns:x="http://schemas.microsoft.com/winfx/2006/xaml" xmlns:d="http://schemas.microsoft.com/expression/blend/2008" xmlns:mc="http://schemas.openxmlformats.org/markup-compatibility/2006" xmlns:local="clr-namespace:EtwStreamViewer" mc:Ignorable="d" Title="MainWindow" Height="350" Width="525"> <Grid> <ListBox ItemsSource="{Binding LogEvents}"></ListBox> </Grid> </Window>
これで準備OK!さっそく実行してみましょう。
ちゃんと 先ほど修正した ReactiveBingViewer のEvent が補足されています。(すごい!)
ちゃんと作り込んだら本格的なeventビユーワも作れそうですね。
まとめ
いつもにも増してまとまりのない記事になってしまいましたが、取り急ぎお試ししてみました!ということでご容赦下さい。