Flame Graphの使用法 -- 学びて時に之を習ふ

11 月にNodeFest Tokyo 2014 で話してきました。タイトルは A Profiling and Monitoring Method for Nodejs Applications というのですが、Lightening Talk ということもあり、そこでカバーできなかったこと、その後加わった便利な機能、経験に基づく Best Practicesなど、皆さんのお役に立ちそうなことを、会場で伺ったご意見を考慮して、何回かに分けて書いてみようと思います。

ちなみに、これは npm と github にソースコードを公開している 「Concurix profiling and monitoring ツール」 についてです。もちろん、無料で使えます。NodeFest Tokyo 2014 に参加されなかった方のためにマニュアルへのリンクをあげておきますと、npmjs.org にある cx-helloworld-readme-ja というパッケージになります。

---

Flame Graph の効用については、Netflix Tech Blog ２０１４年１１月１９日 とか、Brendan Gregg が２０１４年９月１７日のブログで、とても良く説明していますから細かいところは、そちらをご一読いただくとして、一言で言うと Flame Graph はソフトウエア・プログラムの動態を可視化する強力なツールです。Flame Graph による可視化は Concurix には標準で入っているので、今日の私のブログでは、その先を書きます。npmjs.org にある cx-helloworld-readme-ja というパッケージの「技を極める」に述べてある「 flame graphの読み方、解析の仕方」の続きと考えてください。 

前置きが、長くなってしまいました。今日のブログのタイトル「学びて時に之を習ふ」はご存知のように「子曰く」で始まる論語の一節です。何故そういうタイトルにしたかというと、「学びて」とは「プログラムをデザインして、書いて、デバグし、よし、Ship it !」と言った後で「時に之を習う」すなわち、「つらつらとソースコードを読み返し、動態など観て悦に入る」のに Flame Graph を使うのも一興と思ったからです。

そんなことをしているうちに、筆者は思いがけずバグを発見したのです。どういう性質のバグかというと、我々は Concurix ツールをConcurix ツールの開発に使っているのですが、Flame Graph を観て「民のカマドは賑わっておる」などと思っていると、ある時、呼ばれるはずのない関数が Flame Graph に現れているのを発見。Concurix ツールは、対応するソースコードの位置を、JSファイル名と行数でガチに表示しますから、その部分を中心にブレークしてみると、おお、なんと、if 文の条件が間違っておりました。

という訳で、今日のブログのポイントです。Flame Graph の使い方として、それまでは「コールスタックがどうなっているか、どのコード部分にどの位時間がかかっているか」に注目して見ていました。すなわち、Flame Graph の縦方向の積み重ねに注目して関数呼び出し関係を、各々の四角の大きさ（幅）で処理時間を観ていたのです。勿論、それはそれで強力であることに変わりはありませんが、更に、横方向に並んている四角（呼ばれた関数）は妥当な呼ばれ方なのかも注目する価値があるという事でした。これは目からウロコの経験で「学びて時に之を習ふ」という言葉が浮かんだという次第です。

最後に、Ghost のサンプルコードに Concurix を設定してモニタリングを行っている私共のサイトの Flame Graph を以下に示します。リアルタイムで観てみたいという方は、このサイトをアクセスしてみてください。開発マシンなので動いていないこともありますから、「Not Enough Trace Data」と表示された場合は、ゴメンなさい。また、後ほどお試しください。

次回は、Flame Graphとコールバック関数のトレースに関して書いてみたいと思っています。