ダンプ解析入門 - Visual Studioでの可視化によるC#トラブルシューティング

CTOの河合(@neuecc)です。ある日のこと、アプリケーションが突然死！しょうがないのでサーバーに入ってイベントビューアーを見るとそこには……

何の役にも立たない情報が並んでいるのであった。こんなんじゃ原因も分からず、どう対処もできない！

という時に役に立つのがダンプです。ダンプさえあれば、クラッシュ時の情報が手に入り、遥かに解決に向かいやすくなります。ダンプ解析というとハードコアな印象もありますが、最近はツールが充実していることもあり、やってみると意外とイージーです。幾つかの実例とともに、どのように解析していくかを見ていきましょう。

ダンプを収集する

クラッシュは突然に。やってくるので、まずはアプリケーションクラッシュと共に自動的にダンプが収集されるように設定しましょう。ダンプファイルがなければ話は始まりません。

ここではWindows Error Reporting (WER)を使います。マニュアルはCollecting User-Mode Dumpsにありますが、かいつまむとレジストリに手書きすると自動で収集するようになります。

では設定しましょう。regedit.exeを開き Windows Error Reporting\LocalDumps、LocalDumpsキーが存在しない場合は新規に作ります。そしてDumpCount, DumpFolder, DumpTypeを設定。

DumpCountは10, DumpFolderは適当なところ、DumpTypeはフル(2)にしました。再起動は必要なく、これで設定は完了です。

スタックオーバーフローを解析する

一撃即死の定番といったらスタックオーバーフロー。まずは簡単なコンソールアプリケーションを作りましょう。

namespace ConsoleApp93
{
    class Program
    {
        static void HogeHoge(string s)
        {
            HogeHoge(s);
        }

        static void Main(string[] args)
        {
            HogeHoge("hoge-");
        }
    }
}

なるほど即死。からの先程のDumpFolderには

ちゃんと収集されています。では、こいつの解析をしましょう。Visual Studio 2017を開き、.dmpファイルをドラッグアンドドロップすると、ダンプファイルの概要が出ます。

この時点で「例外情報：スレッドのスタックがいっぱいです」によりスタックオーバーフローが原因だとわかりますが、更にアクションから「混合でデバッグ」、あるいは「マネージのみでデバッグ」をクリックしましょう。

ソースコードレベルで丸わかり。これ以上ないぐらい分かりやすいですね、完璧！と、いうわけで、pdbやソースコードがあればそこを組み合わせてクラッシュ時の箇所に止めてくれるので、一発です。なのでできればそれらも合わせておきたいですが、しかし、実際のクラッシュダンプ解析時にないよ、という状況もままあるでしょう。そんな時のケースも見てみます。

とはいえ勿論、ソースコードがあったほうが圧倒的に解決が捗ります。ダンプを取得する際には、pdbやその時のdll一式も含めてコピーし、手元にはその際のリビジョンに戻したソリューションファイルを開いておき、そのVisual Studio上でダンプの解析を始めると、簡単にダンプとソースコードを突き合わせることができます。一手間ではありますが、可能な限りその状態を作っておくと良いでしょう。

いったん、Releaseビルドし、Program.csは削除しておきましょう。これでVisual Studioがソースコードと突き合せられなくなります。

見つかりません、と。一気に情報量が減りました。この状態で、Visual Studioでのダンプ解析に役立つウィンドウがあり、それらを開いていきます。

一つはスレッドウィンドウ。

実際のアプリケーションでは多数のスレッドが動いているはずで、各スレッドの情報や、切り替えての把握が重要になってきます。

もう一つが呼び出し履歴ウィンドウ。

まぁもうスタックオーバーフローだと一目でわかりますね。これはスレッドウィンドウからのスレッド選択と連動しています。

そして最後に、欠かせない最も強力なものが並列スタックウィンドウ。

グラフ表示で、各スレッドとそのスタックの中身を表示してくれます。今回の例のような単純なものではあってもなくても変わりませんが、実際のアプリケーションでは100を超えるスレッドが動いているわけで、それらが俯瞰して見えるのは非常に強力です！

スタックオーバーフローぐらい別に場所すぐ分かるんじゃないの？と思いきや、特定条件が重なったときだけ発生する、あるプルリクエストをマージしてから発生したのだけれどプルリクエストが巨大でちょっとどこだかわからない、というかそもそもスタックオーバーフローなのかどうかもわからない、とにかく突然死する。といった状況下、なくはないというか普通にあると思います。そんな時、ダンプの取得と解析は助けになってくれるでしょう。一発で原因を特定できます。

CPU100%やデッドロックを解析する

クラッシュのほうがダンプ取得に関してはイージーで、実際に困るケースとしてはCPUが100%に張り付いてしまったりアプリケーションが止まってしまったりといった、ハングするケースのほうが多いでしょう。

自動で収集するには、ダンプの取得自体がハイコストな処理なのでややリスキーです。瞬間的に100%なだけで復帰できるものが、ダンプを取得しようとしたばかりに片っ端からアプリ停止して、より深刻な障害に結びつく可能性があります。特定のタイミングで発生することが分かっている場合（たとえば高負荷時のみヤバくなる、など）なら、手動でタイミング見計らってダンプ取得するのもいいかもしれません。何れにせよ、場合によりマチマチで、ベストな回答というのはありません。

手動でダンプ取得する場合、最も簡単なのがタスクマネージャーから「右クリック→ダンプファイルの作成」です。

実際にASP.NETのデッドロックするシチュエーションを作り、解析してみましょう。ASP.NET MVCのテンプレートプロジェクトを作り、Indexを以下のように書き換えます。

public class HomeController : Controller
{
    async Task<string> GetAsync()
    {
        var str = await new HttpClient().GetStringAsync("http://google.com/");
        return str;
    }

    public ActionResult Index()
    {
        var s = GetAsync().Result;
        return View();
    }
}

このコードはasync/awaitによるデッドロックを引き起こします。なぜ？というとSynchronizationContextが待ち合うからで、詳しくは以前に私が発表した以下のスライドに書いてあります。

HttpClient詳解、或いは非同期の落とし穴について from Yoshifumi Kawai

このコードを実行すると、無事ブラウザが真っ白で一向にレスポンスを返してくれなくなります。OK、ではダンプを取りましょう！手元で動かしている場合はIIS Expressがホストしているので、IIS Expressのダンプを取ります。

これを開いて、「混合でデバッグ」から並列スタックで見ると……

右下のグラフエクスプローラーで分かる通り、巨大なツリーになっていてハードコアでわけわからないです。これはネイティブコードが混ざっているからで、正直ネイティブ部分はユーザーコードの外で見てもあまり分からないので（真の全体像を知るという点で使えないわけではない）、省きましょう。「マネージドのみでデバッグ」から始めるのが正解。

すっきりしたグラフが得られました。さて、どこを見るべきか、ですが、こういう場合は長いやつが大抵正解、です。

HomeController.Indexから来て、ManualResetEventSlim.Waitで停止してそうな雰囲気があります。これっぽいですね。

このようにウィンドウを4分割で並べておくと、把握しやすくて便利です。

デッドロック、またはそれに近い状況は様々な原因で起こります。特に起きやすいと感じているのは、プール関連。スレッドプールは伸張に時間がかかるため、用意されたプールを使い切ったあたりからアプリケーションのパフォーマンスが急速に低下します。また、コネクションプールも、通常最大数まで使い切ると、空きが出るまでは同期的に待ち（あるいはタイムアウト）、その間は詰まったような動作をします。それらが複合された結果、全体的に動かなくなってデッドロックと化す複合パターンもありえます。

そのようなときでのダンプと、大量の並列動作を俯瞰して見ることが出来る「並列スタックウィンドウ」は、解析にあたって大きな助けとなるでしょう。

まとめ

よりハードコアなダンプについては、Microsoftのサポートエンジニアの方々がdecode:2017で発表したハードコア デバッギング ～ Windows のアプリケーション運用トラブルシューティング実践というセッションならびに資料が大変詳しいです。Dumpの採取方法からWinDbgによる解析、PerfViewによるCPU負荷の解析まで、実にハードコアに網羅されています。

が、しかし、いきなりハードコアにやる必要はないんですね。Visual Studioによる解析がもっともイージーだと思いますし、存外それで解決できるトラブルも少なくないと思います。ハードコアに入るのは、それで解決できなかったときからでよいわけです、まずは簡単なところから入りましょう。

更により高度な解析、もしくは自動化なども試みるなら、プログラマブルなダンプの解析まで進んでもいいかもしれません。

Microsoft/clrmdを使うことで、ダンプファイルをC#で解析することが可能です。例えば先のIIS Expressのダンプをロードするには

using (var target = DataTarget.LoadCrashDump(@"C:\Users\y.kawai\AppData\Local\Temp\iisexpress.DMP"))
{
    var version = target.ClrVersions[0];

    // dacが見つからない場合もある(MicrosoftのSymbolサーバーから落としてきたい……)
    var runtime = version.CreateRuntime();

    // 以下runtimeを使ってあらゆる解析がプログラマブルにできる！
}

コンソールアプリケーションのダンプだとうまく動くのですが、IIS Expressのものだとうまく動かなかったり。昔のドキュメント？にはGetting the Dac from the Symbol Serverとあったのに、現在は完全に削られていて、自前でうまく合わせないといけないようなのですが……。

ともあれ、C#で自由に解析できるなら、あとはやりたい放題です！WinDbgのコマンドを覚えるぐらいなら、C#とLINQでガリガリ弄って、ウォッチウィンドウや、あるいはLINQPadのDumpなどで確認していったほうが、むしろ強力かもしれません。