NetflixのソフトウェアエンジニアであるYunong Xiao氏は先日,自社の公式技術ブログに,NetflixのWebサイトのUIをNode.jsに移行する作業で氏のチームが直面した,遅延の問題に関する記事を書いた。記事中で氏は,その根本原因を突き止めるために使用した複雑な技術プロセスと,それに伴って,基盤となるAPIフレームワークのリプレースを決意した経緯について説明している。
問題が明らかになった最初の徴候は,APIのいくつかのエンドポイントにおいて要求の遅延時間が増加していること(10ms/時),その時にアプリケーションが予想以上にCPUを消費していることを,チームが認識したことだった。当初の予想は,チームが開発した要求ハンドラに何らかの問題(メモリリークのような)があって,遅延の増加を起こしているのではないか,というものだった。これを確認するためにチームは,コントロール可能な実行環境を立ち上げて,要求ハンドラが発生させている遅延時間と要求全体の遅延時間の両方を測定することにした。合わせてNode.jsのヒープサイズを32GBに拡大した。観測の結果,試験全体を通じて遅延時間とヒープサイズは一定であったにも関わらず,全体的な要求遅延とCPU使用率は上昇を続けることが分かった。
次のアプローチとして,CPUフレームグラフ(Flame Graph)とLinuxのPerfイベントを使って,アプリケーションのCPU使用率のプロファイルを取得することにした。そのフレームグラフ(下図参照)を詳細に調査した結果,Express.jsがrouter.handleとrouter.handle.next関数を頻繁に参照していることが判明した。
Express.jsのコードベースを詳細に調査したところ,次のようなことが明らかになった。
- すべてのエンドポイントのルートハンドラは,ひとつのグローバル配列に格納される。
- 適切なハンドラが見つかるまで,Express.jsは,すべてのハンドラの再帰的な参照と起動を行う。
これについて氏は,次のように述べている。
グローバル配列は,このユースケースの理想的なデータ構造ではありません。Express.jsがハンドラの保存に,なぜmapのような,検索時間が一定のデータ構造を使わなかったのかは分かりません。配列形式のルートから,要求それぞれのルートハンドラをルート配列で見つけるには,負荷の高いO(n)参照が必要になります。さらに悪いことに,この配列は再帰的に探索されます。フレームグラフに高いスタックが見られるのは,このような理由からです。興味深いことに,Express.jsでは [a, b, c, c, c, c, d, e, f, g, h] のように,同一のルートハンドラをいくつも設定することが可能になっています。
ルートcの要求は,最初のcハンドラの位置(この配列では3番目)で終了しますが,dの要求は配列の7番目まで終了しません。a,b,それにcの複数のインスタンスでは,無駄な時間を費やすことになるのです。
Express.jsがルートを格納する方法についてもう少し詳しく知るために,チームは次のようなExpress.jsのサンプルを作った。
var express = require('express'); var app = express(); app.get('/foo', function (req, res) { res.send('hi'); }); // add a second foo route handler app.get('/foo', function (req, res) { res.send('hi2'); }); console.log('stack', app._router.stack); app.listen(3000);
結果は次のようになった。
stack [ { keys: [], regexp: /^\/?(?=/|$)/i, handle: [Function: query] }, { keys: [], regexp: /^\/?(?=/|$)/i, handle: [Function: expressInit] }, { keys: [], regexp: /^\/foo\/?$/i, handle: [Function], route: { path: '/foo', stack: [Object], methods: [Object] } }, { keys: [], regexp: /^\/foo\/?$/i, handle: [Function], route: { path: '/foo', stack: [Object], methods: [Object] } } ]
この試験からは,Express.jsはルートの重複を適切に処理できていない,という結論が得られた。氏は次のように指摘する。“/fooに2つの同じルートハンドラがあることに注意してください。Express.jsが,ひとつのルートに複数のルートハンドラチェーンがある場合は,必ずエラーをスローしていればよかったのですが。”
自分たちのソースコードを詳細に調査した結果,チームは問題を特定した。問題は,1時間に10回実行される周期関数の中にあった。外部のソースを参照して,ルートハンドラをリフレッシュすることを主な目的とする関数だ。チームがそのコードをフィックスすると,重複するルートハンドラが追加されなくなり,遅延とCPU使用率の上昇も解消した。
この出来事の結果としてチームの得た結論を,氏は次のように要約している。
第1に,サードパーティのソフトウェアを製品に採用するには,事前にそれらを完全に理解しておく必要があります。私たちはコードベースの詳細な調査をせずに,Express.jsのAPIについて,誤った仮定をしていました。その結果,Express.js APIの誤った使用が,パフォーマンス問題の根本的な原因となったのです。
第2に,パフォーマンスの問題に対しては,観測することが最も重要です。アプリのCPU時間の大部分を消費している場所を特定する上で,フレームグラフが素晴らしい洞察を与えてくれました。Node.jsのスタックをサンプリングしてフレームグラフとして視覚化できなかったとしたら,この問題が解決できたとはとても思えません。
私たちは観測性をさらに向上させるべく,さらに優れた洞察と可視性,アプリケーションのコントロールを提供してくれる,Restifyへの移行を行っています。