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

2.6K Views

March 12, 19

#Node.js #パフォーマンスチューニング #プロファイリング #BFF #Webアプリケーション

スライド概要

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

Yahoo!デベロッパーネットワーク

@ydnjp

スライド一覧

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

またはPlayer版

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

（ダウンロード不可）

関連スライド

深層学習による自然言語処理入門: word2vecからBERT, GPT-3まで

Yahoo!デベロッパーネットワーク 165.2K

ゼロから始める転移学習

Yahoo!デベロッパーネットワーク 86.6K

ヤフーにおける WebAuthn と Passkey の UX の紹介と考察 #idcon #fidcon

idcon fidcon

Yahoo!デベロッパーネットワーク 74.2K

OpenID Connectとネイティブアプリを取り巻く仕様と動向 Yahoo! JAPANの取り組み #openid #openid_tokyo

openid openid_tokyo

Yahoo!デベロッパーネットワーク 58.1K

運用業務とスクラムは本当に組み合わせにくいのか︖運用業務が大半を占めるプロダクト開発での試行錯誤

devsumi

Yahoo!デベロッパーネットワーク 36K

ヤフーのオンプレ機械学習基盤AIPFについて #ml_kubernetes

ml_kubernetes

Yahoo!デベロッパーネットワーク 29.3K

各ページのテキスト

自己紹介 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

開発した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

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

ベンチマークを取るツール 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

ベンチマークをとるときの構成記事サービスランキングサービスベンチ用仮想サーバ 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

http://dummy-domain.yahoo.co.jp/

11.

12.

13.

14.

15.

16.

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

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

https://nodejs.org/en/docs/guides/simple-profiling/

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.

23.

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.

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.

29.

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

30.

改善２：社内製のライブラリの実装改善課題 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.

改善３：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

https://github.com/inversify/InversifyJS/blob/master/wiki/scope.md

33.

改善４：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.

35.

改善５：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

https://nodejs.org/api/cluster.html

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.

改善６：バックエンド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.

40.

41.

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.

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.