MSBuildのバイナリログを見る

はじめに

MSBuildには、15.3よりバイナリログというものが、ログの出力形式として追加されている。
使いこなせばMSBuildのトラブルシューティング、解析等に役立つと思うので、読み方などを書いていく。

なお、msbuild自体についてはこの記事では解説しないので、docsのドキュメントを参照のこと

バイナリログとは

まずはバイナリログとはどういうものなのか、ということを説明したい。
詳しい内容は githubのドキュメント を参照。

どのようなものなのか

MSBuildで実行したタスク、設定されたプロパティ等の情報が記載されている、いわゆる実行ログである。
フォーマットに関しては厳密にドキュメント化されているというわけではなく、使用者側は用意されたAPIを用いて
アクセスするような形となっている。
ソースは公開されているので、興味のある人は見てみるのもいいかもしれない。

どのような時に使うのか

考えられるのは以下のケース

• MSBuildタスクのトラブルシューティング
  • 独自タスク等を作成した時の挙動確認(パラメーターは渡されているか、必要なタスクが実行されているか等)
• バイナリログからのプロジェクト解析
  • Buildalyzer 等のようにビルド結果から何らかの処理を行いたい場合
    • Buildalyzerに関しては、更に後述の構造化ログで再構成して解析している

利点

• コンパクトかつ詳細な情報
  • msbuildのdiagnosticsレベル相当の情報を取得可能で、かつファイルサイズがテキスト出力に比べると小さくなっている(10倍から20倍程度)
  • 出力によるCPUパワー的なオーバーヘッドも少ない
• プログラムで解析可能
  • テキストログではどうしても非定型になる所が出てきて、解析が大変だが、こちらは解析用のAPIを使って情報の取捨選択が容易に可能
• 他の形式に再解釈が可能
  • 例えばテキストログや、独自形式に変換することも可能

生成方法

msbuildコマンドを実行する時に/blオプション指定する。デフォルトではmsbuild.binlogという名前で生成されるが、/bl:[ファイル名]で任意のファイルに出力することが可能。
dotnet-sdkから生成したい場合は、dotnet msbuildコマンドを使用する。dotnet buildコマンドの場合、dotnet build -bl [ファイル名]で指定可能。

ログビューアーで見る

APIから読み取ることも可能だが、GUIで俯瞰的に見たい場合、 MSBuild Log Viewerを使用するのが推奨される。
なお、現在(v2.0.64)はWPFで書かれていることもあり、Windows専用の模様。この辺り、dotnet-sdk-3.0が正式リリースになれば、状況が変わってくるかもしれない。
ソースからmacOS版(Avaloniaを使用)をビルドできるので、これを使うことも可能。v2.1.561の時点ではまだリリースアセットの中に入ってないが、その内ビルド済みバイナリが入ってくるかも。

構造化ログ(StructuredLog)に関して

MSBuild Log Viewerでは、前述のBinaryLogを更にアプリケーション向けに再構成したStructuredLogに変換して、解析を行う。
これは、BinaryLogが逐次的な出力であるのに対して、DOM的なツリー構造を作るためのものとなっている。
BinaryLogよりも更にサイズが1/10程度になるが、BinaryLogに再構成するのは現状難しいとのことなので注意。
また、ツリー構造を全てメモリ上に展開するのが前提となっているため、巨大なログファイルを扱う場合は注意が必要。

ライブラリはnetstandardなので、非Windows環境などで解析を行いたい場合は役に立つかもしれない。

基本画面

画面を起動して、生成したログファイル(*.binlogあるいは*.buildlog)を開くと、以下のような画面になる。

基本的には左側の"Search Log"タブで絞りこみ、右側の"Log"タブを開いていって、確認するという流れとなる。

どのプロジェクトが、どの順番で解析されたか確認する

MSBuildがどのような順序でファイルを解析されたかを知りたい場合、Evaluationツリーを見る。

どのような順序で処理されたか、また、何を処理したか(プロパティの割り当て、タスク実行等)ということがここで確認できる。
例えばslnのビルド等、複数プロジェクトにまたがるビルドをした場合、複数のプロジェクトに対してこのツリーができる。

ターゲットごとに、どのようなプロパティとアイテムが設定されたか確認する

例えば、ビルド時にどのようなプロパティが設定され、どのようなアイテムが対象になったかということを知りたい場合、プロジェクトツリーの中を見ることになる。
右ツリーの'プロジェクト "[プロジェクト名]" ([ターゲット名])'というツリーを開いて、その直下にある"Properties"と"Items"が、それぞれターゲット内でPropertyGroupとItemGroupに最終的にセットされた値という事になる。
なお、slnビルドのように、親子関係が存在するターゲットがある場合、ビルドがツリー上になるので、ツリーを辿って行ってみる必要がある。

個別タスクとタスクに渡されたパラメーターを確認する

msbuildには、大雑把に言ってProject-Target-Taskという関係があるが、その最小単位であるTaskにどのようなパラメーターが割り当てられたかを確認したい場合、各プロジェクトの"Target"ノードの配下に"Task"ノードがあるので、そこを確認すれば、どのようなパラメーターが渡されたか、確認が可能。ついでに経過秒数も確認できる。

なお、探したいTaskの名前がわかっていれば、左側の"Search Log"で$task [タスク名]というように入力すれば、目当ての情報を絞り込むことができる。Taskはちょっとしたプロジェクトでも大量にあるので、活用できると思う。

解析されたファイルがどこに存在するか確認する

解析されたファイルのパスを知りたい場合、左の"Files"タブで、パスを確認できる。
バイナリログを作成した時と同じディレクトリ構成であれば、その中身も確認が可能。

終りに

MSBuildの解析ということで、普段は立ち入ることは少ない領域かもしれないが、自分でMSBuildを色々ハックしたい場合は非常に役立つものなので、役に立てれば幸い。
後は、せっかく解析部分がライブラリとしてあるので、時間があれば、プログラム的に解析するやり方も紹介できればいいかなと思っている。