起動中のNode.js

node.jsを使用して、Netflix.com Webアプリケーションの新世代を作成しています。 数か月前にNodeConf.euで発表したプレゼンテーションから、この旅行について詳しく知ることができます。 今日は、アプリケーションの新しいスタックのパフォーマンスを調整した経験を共有したいと思います。



node.jsアプリケーションのリクエストの遅延が時間の経過とともに増加することに気付いたとき、最初に問題が発生しました。 さらに、予想よりも多くのプロセッサリソースを使用し、これは遅延時間と相関していました。 Linux EC2環境で新しいツールとパフォーマンス分析技術を使用して原因を検索する間、一時的な解決策として再起動を使用する必要がありました。

火が燃え上がる

node.jsアプリケーションのリクエストの遅延は時間の経過とともに増加することに気付きました。 そのため、一部のサーバーでは、遅延が1時間ごとに1ミリ秒から10ミリ秒に増加しました。 また、CPU使用率の増加に依存していることもわかりました。







このグラフは、時間に対するミリ秒単位のリクエスト遅延の期間を示しています。 各色は、AWS AZの異なるインスタンスを表します。 遅延は1時間あたり10ミリ秒ずつ絶えず増加しており、再起動前に60ミリ秒に達していることがわかります。

消火

最初に、これらは独自のリクエストハンドラのメモリリークである可能性があり、それが遅延の原因になる可能性があることを提案しました。 リクエストハンドラーでのレイテンシーとリクエスト遅延の合計期間を測定するメトリックを追加することにより、分離されたアプリケーションの負荷テストを使用してこの仮定をテストしました。また、node.jsで使用されるメモリのサイズを32ギガバイトに増やしました。



ハンドラーの遅延は一定であり、1ミリ秒に等しいことがわかりました。 また、プロセスで使用されるメモリ量も変更されず、約1.2ギガバイトに達することもわかりました。 ただし、全体的な遅延とプロセッサ使用率は増加し続けました。 これは、ハンドラーがそれとは何の関係もないことを意味し、問題はスタックでより深くなりました。



何かがリクエストの処理に60ミリ秒を追加しました。 アプリケーションによるプロセッサの使用をプロファイルし、受信したデータを視覚化する方法が必要でした。 Linux Perf Eventsとフレームグラフプロセッサが助けになりました。



フレームグラフに精通していない場合は、ブレンダングレッグの優れた記事を読むことをお勧めします。 以下がその概要です（記事から直接）：

• 各ブロックは、スタック上の機能を示します（スタックフレーム）
• Y軸は、スタックの深さ（スタック内のフレームの数）を示します。 上のブロックは、プロセッサによって実行された機能を示し、下のすべてはその呼び出しのスタックです。
• X軸は、関数呼び出しの数を示します。 ほとんどのグラフのように、関数が費やした時間は表示されません。 順序は関係なく、ブロックは単純に辞書式順序でソートされます。
• ブロックの幅は、関数がプロセッサによって実行された合計時間、またはそれを呼び出した関数の実行時間の一部を示します。 関数の広いブロックは、狭いブロックよりもゆっくり実行したり、単に頻繁に呼び出すことができます。
• 関数が複数のスレッドで実行された場合、呼び出しの数は時間を超える場合があります。
• 色には特別な意味はなく、「暖かい」トーンから任意の順序で決定されます。 フレームグラフ[文字通り「フレームグラフィック」。 約 翻訳者]は、アプリケーションコードの「最もホットな」場所を示すため、そう呼ばれます。

以前、node.jsフレームグラフは、Dave Pachecoのjaveck（）と組み合わせたDTraceシステムでのみ使用できました。 ただし、Google V8チームは最近、V8エンジンにperf_eventsサポートを追加しました。これにより、LinuxでJavaScriptをプロファイルできます。 この記事では、BrendanはLinuxでフレームグラフを作成するためにnode.js 0.11.13に登場した新しい機能の使用について説明しました。







このリンクにより、SVGでのアプリケーションの元のインタラクティブフレームグラフを見ることができます。



すぐに、アプリケーション（Y軸）の非常に大きなスタックに注意できます。 また、時間がかかることも明らかです（X軸）。 route.handle



と、これらのスタックフレームはExpressの route.handle



およびroute.handle.next



関数への参照でいっぱいであることがroute.handle



。



Expressソースコードに2つの興味深いポイント¹が見つかりました。

• すべてのパスのルートハンドラーは1つのグローバル配列に格納されます
• Expressは、適切なルートが見つかるまで再帰的に反復し、すべてのハンドラーを呼び出します

この場合、グローバル配列は最適なデータ構造ではありません。ルートを見つけるには、平均してO（n）回の操作が必要になるためです。 Expressの開発者が永続的なデータ構造（たとえば、ハンドラーを格納するためのハッシュテーブル）を使用しないことにした理由は明らかではありません。 この状況は、アレイが再帰的にバイパスされるという事実によって悪化します。 これが、炎グラフでこのような高いスタックを見た理由を説明しています。 Expressでは、1つのルートに複数のハンドラーを設定できることも興味深いです。

 [a, b, c, c, c, c, d, e, f, g, h]
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

この場合、ルートc



の検索は、最初の適切なハンドラーが見つかったときに終了します（配列の2番目の位置）。 ただし、ルートハンドラーd



（配列の位置6）を見つけるには、 c



いくつかのインスタンスの呼び出しに余分な時間を費やす必要がありc



。 これを簡単なExpressアプリケーションでテストしました。

 var express = require('express'); var app = express(); app.get('/foo', function (req, res) { res.send('hi'); }); //         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] } } ]
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

/foo



ルートには2つの同一のハンドラーがあることに注意してください。 1つのルートに複数のハンドラーがある場合は、Expressがエラーをスローするといいでしょう。



ここで、ハンドラーを使用した配列の一定の増加により遅延が発生したと仮定しました。 ほとんどの場合、ハンドラーはコードのどこかに複製されています。 リクエストハンドラーの配列を表示する追加のロギングを追加し、1時間あたり10個の要素で成長することに気付きました。 上記の例のように、これらのハンドラーは互いに同一でした。



何かが1時間あたり10個の同一の静的ルートハンドラーをアプリケーションに追加しました。 さらに、これらのハンドラーを反復処理する場合、各ハンドラーを呼び出すコストは約1ミリ秒かかることがわかりました。 これは、応答遅延が1時間あたり10ミリ秒増加したときに見たものと相関しています。



これは、外部ソースからのコード内のハンドラーの定期的な更新（1時間に10回）が原因であることが判明しました。 これを実装するには、古いハンドラーを削除し、新しいハンドラーを配列に追加します。 残念ながら、この操作の間も、常に静的ルートのハンドラーを追加しました。 Expressでは、同じルートに複数のハンドラーを追加できるため、これらの複製はすべてアレイに追加されました。 最悪なことに、それらはすべて残りの前に追加されました。つまり、ExpressがサービスのAPIハンドラーを見つける前に、静的ルートのハンドラーを数回呼び出します。



これは、リクエストの遅延が1時間あたり10ミリ秒増加した理由を完全に説明しています。 実際、コードのエラーを修正した後、遅延時間の一定の増加とCPU使用率の増加は停止しました。







このグラフは、コードの更新後、遅延時間が1ミリ秒に短縮されたことを示しています。

煙が消えたとき

どのような経験がありますか？ まず、本番環境で使用する前に、コードで依存関係がどのように機能するかを完全に理解する必要があります。 Express APIはコードを検査せずに機能すると誤った仮定をしました。 Express APIの誤用は、パフォーマンスの問題の最終的な原因です。



第二に、パフォーマンスの問題を解決するには、可視性が最も重要です。 フレームグラフは、アプリケーションが最も時間とCPUリソースを消費する場所を十分に理解しました。 node.jsスタックを取得してフレームグラフを使用して視覚化できないことで、この問題をどのように解決できるか想像できません。



視覚化を改善するために、 Restifyに移行しています 。これにより、アプリケーションの制御を改善できます² 。 これはこの記事の範囲を超えているため、Netflixでnode.jsを使用する方法についてのブログ投稿を読んでください。



このような問題を私たちと一緒に解決したいですか？ 私たちのチームは、node.jsスタックを扱うエンジニアを探しています。



投稿者Yunun Xiao @yunongx



注：

1. 特に、このコードの一部 。 next()
   
   
   
   関数は、ハンドラーの配列を反復処理するために再帰的に呼び出されることに注意してください。
2. Restifyは、 DTraceサポートからnode-bunyanとの統合まで、アプリケーションの視覚的エクスペリエンスを向上させるための多くのメカニズムを提供します 。

翻訳者のメモ：

1. Netflixとは関係ありません。 しかし、私は意図的に空席へのリンクを残しました、それが誰にとっても有用であるならば、私は心からうれしく思います。
2. 元の記事に対するコメントは、Expressがハンドラーを保存するためのデータ構造としてハッシュテーブルを使用しない理由を説明しています。 理由は、必要なハンドラーを選択するために使用される正規表現がハッシュテーブルのキーにならないためです。 また、文字列として保存する場合は、ハッシュテーブルのすべてのキーを比較する必要があります（ただし、ルートに2番目のハンドラーを追加すると、少なくとも警告がスローされる可能性があるという事実はキャンセルされません）。
3. また、 Eran Hammer（ ハピ貢献者の1人） による詳細な回答と、それに続く議論を読むこともできます。

翻訳に関するコメントやコメントはプライベートメッセージで歓迎されます。



UPD ：丁寧な読者は、翻訳者が元の記事の著者の名前を誤って転記したことに気付きました。 domix32とlanyからのヒントをありがとう。