Yahoo!ニュースにおけるBFFパフォーマンスチューニング事例

1.6K Views

March 12, 19

スライド概要

2019/03/12 : Node学園 33時限目
https://nodejs.connpass.com/event/122297/

profile-image

2023年10月からSpeaker Deckに移行しました。最新情報はこちらをご覧ください。 https://speakerdeck.com/lycorptech_jp

シェア

埋め込む »CMSなどでJSが使えない場合

関連スライド

各ページのテキスト
1.

Yahoo!ニュースにおける BFFパフォーマンス チューニング事例 2019/03/12 矢端 喜楽 後藤 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved.

2.

自己紹介 noimage 矢端 智光 2012新卒からニュースを担当。アプリの新規開発やスピーカー開発を経て今に至る。 AndroidやSpring BootでJavaばかり触っていたが、今期からScriptがついた。はじめてのwebページ新規開発。 noimage 喜楽 智規 (@gladenjoy) 2016新卒からニュース一筋約3年。PHP→Java→TypeScriptと渡り歩いて来た。フロントエンド・BFFあたりの開発に従事。 noimage 後藤 拓実(@oTheRwoRldy) 2012新卒からニュースを担当。フロントエンド技術、API設計、アプリケーションのアーキテクチャに興味。TL。 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 2

3.

今日の内容 Node.js経験の浅いメンバーによるパフォーマンス改善のお話 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 3

4.

本題 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved.

5.

開発したWebアプリケーションの概要 名称:NewsWeb news.yahoo.co.jp配下の一部ページを担うWebアプリケーションです。 キーワード Node.js / TypeScript / React / Redux / Express / InversifyJS / axios / Storybook / Backend for Frontend / Server Side Rendering / Layered Architecture 実行環境 Pivotal Cloud Foundry(Private PaaS) 開発メンバー 10名弱 東京拠点と九州拠点のメンバーで開発を行っています 補足 Javaで一度書いた後、SSRの課題が出てきたのでNode.jsに置き換えています Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 5

6.

アプリケーションの概要図 記事サービス 旧システム ランキング サービス Edge Server NewsWeb Redis Cluster トピックス サービス … お知らせ サービス ※省略していますが、Edge Serverの後ろには他にもフロントエンドサーバがあります。 段階的にページを移行しており、現時点でYahoo! ニュースの全リクエストを新システムが担っているわけではないです。 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 6

7.

パフォーマンスに関する要件 秒間リクエスト数 - 4000req/s以上 レスポンスタイム - 99パーセンタイル値が1秒以下 - 80パーセンタイル値が0.5秒以下 現行のシステムの性能をベースにした要件で、概ね上記を満たしたい。 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 7

8.

ベンチマークを取るツール Apache Bench(ab)を利用 Apache HTTP Serverに付属するベンチマークツール yumなどでhttpdをインストールするか、apr-utilパッケージを入れることで利用できます。 $ sudo yum install httpd $ sudo yum install apr-util ※今回はabを使いましたが、abでなければいけない理由は特にありません。 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 8

9.

ベンチマークをとるときの構成 記事サービス ランキング サービス ベンチ用 仮想サーバ NewsWeb Redis Cluster トピックス サービス … お知らせ サービス Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. - 本番相当の環境に1インスタンス用意 - ベンチマーク用のVMからabを実行 すべてローカル環境で実行する方法もあるが 今回はこの方法でベンチマークを実施した。 Wi-Fiなどネットワークがボトルネックになる ことがあるので注意する。 9

10.

ベンチマークの手順 並列数を増加させながら秒間リクエスト数が頭打ちになる箇所を探る $ ab -t 30 -c 5 -k http://dummy-domain.yahoo.co.jp/ $ ab -t 30 -c 10 -k http://dummy-domain.yahoo.co.jp/ $ ab -t 30 -c 15 -k http://dummy-domain.yahoo.co.jp/ -k: Keep Alive有効 -t: ベンチマークの実行時間(sec) -c: 並列アクセス数 $ ab -t 30 -c 20 -k http://dummy-domain.yahoo.co.jp/ $ ab -t 30 -c 25 -k http://dummy-domain.yahoo.co.jp/ Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 10

11.

ベンチマークの結果(改善前) 並列数毎の秒間リクエスト数の推移 30 秒間リクエスト数 25 20 15 10 5 0 5 10 15 20 25 30 35 40 45 50 並列数 改善前 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 11

12.

ベンチマークの結果(改善前) Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 12

13.

ベンチマークの結果 想像以上にパフォーマンスが良くない - 秒間リクエスト数は23req/s程度で頭打ち - レスポンスタイムも並列数に比例してあがっていく 多数のインスタンスを並べれば要件は満たせるが… 何らかのボトルネックがありそうな気がする。 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 13

14.

さてどうしよう Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved.

15.

先入観 「SSR時のrenderToNodeStreamが重いのかなと思っています」 喜楽 「SSR自体重いと聞きますし、確かに怪しそうですね」 後藤 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 15

16.

まずはボトルネックを特定したい - 地道にconsole.time, console.timeEndを仕込む? - sjspのようなプロファイリングコードを挿入してくれるツールを使う? - functionの実行時間と実行回数が出力できる - nodeの—profオプションを使う? - ちょっと調べた感じ難しそう… Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 16

17.

Nodeサポートチームに相談 「ボトルネック特定するベストプラクティスを教えてほしいです」 後藤 「まずは profile を取ることからだと思います」 Nodeサポート Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 17

18.

プロファイルをとる? Node.js (V8)に備わっているプロファイリング機能がある --profオプションを指定してアプリケーションサーバを起動すると isolate-0xnnnnnnnnnnnn-v8.logというファイルにログが出力される $ node —prof index.js このファイルにnode --process-profを適用することで読める形に変換される $ node —process-prof isolate-0xnnnnnnnnnnnn-v8.log > result.txt Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. Easy profiling for Node.js Applications | Node.js https://nodejs.org/en/docs/guides/simple-profiling/ 18

19.

プロファイル結果の見方 プロファイル結果はいくつかのセクションに分かれているが、 まずはSummaryセクションを確認する。 [Summary]: ticks total nonlib 186 9.2% 9.3% 1788 88.5% 89.8% 39 1.9% 2.0% 29 1.4% 18 0.9% name JavaScript C++ GC Shared libraries Unaccounted 今回の場合、C++ のCPU Timeが多いことがわかる Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 19

20.

プロファイル結果の見方 C++の処理の内訳を確認すると、File関連の処理が重そう [C++]: ticks 453 379 90 85 total nonlib name 22.4% 22.7% t node::fs::Open(v8::FunctionCallbackInfo<v8::Value> const&) 18.8% 19.0% T node::contextify::ContextifyScript::New(v8::FunctionCallbackInfo<v8::Value> const&) 4.5% 4.5% t node::fs::InternalModuleReadJSON(v8::FunctionCallbackInfo<v8::Value> const&) 4.2% 4.3% t node::fs::Read(v8::FunctionCallbackInfo<v8::Value> const&) Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 20

21.

プロファイル結果の見方 Bottom upの項目を確認すると、readFileSyncが重そう [Bottom up (heavy) profile]: ticks parent name 453 22.4% t node::fs::Open(v8::FunctionCallbackInfo<v8::Value> const&) 453 100.0% T v8::internal::Builtin_HandleApiCall(int, v8::internal::Object**, v8::internal::Isolate*) 453 100.0% LazyCompile: ~openSync fs.js:429:18 453 100.0% LazyCompile: ~readFileSync fs.js:341:22 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 21

22.

ボトルネックの可視化 重い箇所のあたりはついてきた。 ボトルネックをコードレベルで特定するのに以下のツールを使う。 - flamebearer - node --inspect Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 22

23.

flamebearerによる可視化 プロファイルログをフレームグラフで表示してくれるツール $ node --prof-process --preprocess -j isolate*.log | flamebearer Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 23

24.

flamebearerによる可視化 パスを一部を指定するとハイライト表示してくれる(緑色の部分) Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 24

25.

node —inspect --inspectを付けてnodeを立ち上げることで、Chromeと連携してデバッグが可能 $ node —inspect dist/index.js Debugger listening on ws://127.0.0.1:9229/0dbdaf5f-7012-4ad0-8693-4af2906a9fb7 For help, see: https://nodejs.org/en/docs/inspector 起動後、chrome://inspect/ を開くと 実行中のプロセスにアタッチできる Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 25

26.

node —inspect Chart表示が視覚的に時間がかかっている箇所を特定しやすくおすすめ Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 26

27.

わかったこと JSON.parseの頻繁な呼び出しがボトルネックになっていた - axios-cache-adapterのキャッシュ結果が文字列で保持されており、 キャッシュ取得時はJSON.parseしていた - JSON.parseは同期処理なためボトルネックに Intl.DateTimeFormatがボトルネックになっていた - 社内製ライブラリで使われていた DIコンテナからインスタンスを取り出すとき毎回constructorが呼ばれていた - constructor内でreadFileSyncがあった - Spring Bootの経験からデフォルトがシングルトンだと思い込んでいた Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 27

28.

それぞれ対応 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved.

29.

改善1:axiosのキャッシュパフォーマンス改善 課題 axios-cache-adapterのキャッシュ結果が文字列で保持されており、 キャッシュ取得時は毎回JSON.parseしていた。 NewsWebではバックエンドAPIの数が多く、また、 JSON.parseは同期処理なためボトルネックになっていた。 対応 axiosのキャッシュアダプタを自作。 JSON(文字列)ではなくオブジェクトをキャッシュして返すように変更した。 ※ボトルネック解消を目的としているため、これが設計として良いかどうかは別の問題です Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 29

30.

改善2:社内製のライブラリの実装改善 課題 Intl.DateTimeFormatを使ったある社内ライブラリ(ExpressのMiddleware) の処理が重く、ボトルネックになっていた。 対応 ライブラリの開発者にDate.toUTCStringを使った実装へ変更してもらい、 そちらを利用するようにした。 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 30

31.
[beta]
参考: Intl.DateTimeFormatのパフォーマンス
1万回のループで検証。1000倍近いパフォーマンスの差がありそう。
検証コード
const date = new Date(Date.UTC(2012, 11, 20, 3, 0, 0));
console.time('Intl.DateTimeFormat');
for(let i = 0; i < 10000; i++) {
new Intl.DateTimeFormat('en-US').format(date);
}
console.timeEnd('Intl.DateTimeFormat');

実行結果
$ node index.js
Intl.DateTimeFormat: 5991.971ms
Date.toUTCString: 5.954ms

console.time('Date.toUTCString');
for(let i = 0; i < 10000; i++) {
date.toUTCString();
}
console.timeEnd('Date.toUTCString');

Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved.

31

32.

改善3:DIコンテナ内のインスタンスをシングルトンに 課題 DIコンテナのインスタンスを参照する度にコンストラクタが実行されている。 コンストラクタ内でReadFileSyncするクラスがありボトルネックになっていた。 対応 コンテナにSingletonスコープでオブジェクトを登録をした。 // 修正前 container.bind(DISymbols.TopicsService).to(TopicsService); // 修正後 container.bind(DISymbols.TopicsService).to(TopicsService).inSingletonScope(); Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. https://github.com/inversify/InversifyJS/blob/master/wiki/scope.md 32

33.

改善4:App起動時にDIコンテナのwarmup 課題 InversifyJSのコンテナからオブジェクトを取り出すとき、 コンストラクタが実行されるため、初回の呼び出しが遅い。 対応 App起動時に、コンテナに登録された全オブジェクトをgetし、 コンストラクタを実行しておく。 // 予めDI Containerのすべてを呼び出して、singletonインスタンスを初期化する // typescriptのチェックを回避するために型定義をして再代入しています const symbols: { [key: string]: symbol } = { ...DISymbols }; for (const key in symbols) { if (key) { container.get(symbols[key]); } } Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 33

34.

それ以外にも気づきベースで対応したこと ボトルネック調査の結果とは別に、以下の改善の実施 - Clusterモジュールの利用 - バックエンドAPIへのKeep Alive対応 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 34

35.

改善5:Clusterモジュールの導入 課題 Private PaaS は1インスタンスあたり8コア割り当てられていた。 Node.jsはデフォルトでは1コアしか使わないため、有効活用できていなかった。 対応 Node.jsの標準モジュールのClusterモジュールを導入した。 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. https://nodejs.org/api/cluster.html 35

36.
[beta]
Clusterモジュールの実装
得られる恩恵の割に非常に導入が容易です。
導入前

導入後

import express from 'express';

import cluster from 'cluster';
import express from 'express';
import os from 'os';

const port = process.env.PORT || '3000';
const app = express();
app.listen(port);

const port = process.env.PORT || '3000';
if (cluster.isMaster) {
for (let i = 0; i < os.cpus().length; i++) {
cluster.fork();
}
cluster.on('exit', worker => {
cluster.fork();
});
} else {
const app = express();
app.listen(port);
}

Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved.

36

37.

補足:Clusterモジュールとnode --inspect Clusterモジュールを導入した後、node --inspectを使うと 各プロセスでデバッグ機能が有効になってしまい使い勝手が悪い 例えば、以下のように--inspectパラメータが指定されているかを判定し、 Clusterモジュールを使わずに起動できるようにしておくと捗ります。 const debug = /--inspect/.test(process.execArgv.join(' ')); if (debug) { // expressを起動 } else { // clusterモジュールでforkして、アプリケーションを起動 if (cluster.isMaster) { // fork... } else { // expressを起動... } } Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 37

38.

改善6:バックエンドAPIへのKeep Alive対応 課題 バックエンドAPIへのリクエスト時にKeep Aliveが有効になっていなかった。 対応 axiosに以下のように設定をしてKeep Aliveを有効化 const axiosClient = axios.create({ timeout, adapter: createCacheAdapter(axios, { maxAge }), httpAgent: new http.Agent({ keepAlive: true }), httpsAgent: new https.Agent({ keepAlive: true }) }); 特に、ユーザ情報を含むようなRedisにキャッシュできないAPIに対して効果 接続時のレイテンシ低減、APIサーバの負荷軽減に繋がる。 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 38

39.

再ベンチマーク Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved.

40.

対応実施後の性能を要件毎にみていきます 以下の3パターンに分けて、再度性能評価を行いました。 - 対応前 - Clusterモジュール導入を除く改善実施後 - Clusterモジュール導入を含んだ改善実施後 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 40

41.

要件のおさらい 秒間リクエスト数 - 4000req/s以上 レスポンスタイム - 99パーセンタイル値が1秒以下 - 80パーセンタイル値が0.5秒以下 現行のシステムの性能をベースにした要件で、概ね上記を満たしたい。 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 41

42.

要件のおさらい 秒間リクエスト数 - 4000req/s以上 👈 レスポンスタイム - 99パーセンタイル値が1秒以下 - 80パーセンタイル値が0.5秒以下 現行のシステムの性能をベースにした要件で、概ね上記を満たしたい。 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 42

43.

秒間リクエスト数の比較 Clusterモジュールを除いた改善で1インスタンスあたり57req/sec、 Clusterモジュール導入で330req/sec程度の性能がでることがわかりました。 並列数ごとの秒間リクエスト数 400 350 300 250 200 150 100 50 0 対応前 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. Cluster以外の対応後 Cluster含む対応後 43

44.

改善の結果 必要インスタンス数の大幅な削減 1インスタンス あたりのreq/sec 4000 req/secに必要な インスタンス数 対応前 23 req/sec 約174 インスタンス Cluster導入前 57 req/sec 約70 インスタンス Cluster含む対応後 330 req/sec 約12 インスタンス Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 44

45.

要件のおさらい 秒間リクエスト数 - 4000req/s以上 レスポンスタイム 👈 - 99パーセンタイル値が1秒以下 - 80パーセンタイル値が0.5秒以下 現行のシステムの性能をベースにした要件で、概ね上記を満たしたい。 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 45

46.

80パーセンタイル値のレスポンスタイム数の比較 Cluster以外の対応で30並列、Cluster込で200並列まで、目標値の0.5秒を満 たしていることがわかります。 80パーセンタイル値のレスポンスタイム比較 4.5 4 3.5 3 2.5 2 1.5 👈 1 0.5 0 対応前 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. Cluster以外の対応後 Cluster含む対応後 46

47.

99パーセンタイル値のレスポンスタイム数の比較 Cluster以外の対応で25並列、Cluster込で200並列まで、目標値の1.0秒を満 たしていることがわかります。 99パーセンタイル値のレスポンスタイム比較 4.5 4 3.5 3 2.5 2 👈 1.5 1 0.5 0 対応前 Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. Cluster以外の対応後 Cluster含む対応後 47

48.

まとめ - 以下のようなツールでボトルネックの調査ができる - node --prof - node –inspect - flamebearer - 想像でCPUバウンド/同期的な処理を疑うのではなく、 プロファイルを取ってボトルネック特定→改善をするのが近道 - 今後 - 継続的なパフォーマンス改善をしていきたい - 今わかっている限りだとmoment-duration-formatが重そう Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved. 48

49.

EOP Copyright (C) 2019 Yahoo Japan Corporation. All Rights Reserved.