Perl Hackers Hub

第56回 AWS X-Rayによる分散トレーシング―マイクロサービスのボトルネック,障害箇所の特定(3)

この記事を読むのに必要な時間:およそ 3 分

(1)こちら⁠2)こちらから。

実際の分散Webアプリケーションの解析

(3)からは,実際の分散Webアプリケーションをトレースしてみましょう。

例として,2018年10月に開催されたISUCON8注1本選問題を取り上げます。この問題は,運営が用意したブラックボックスとしての外部のWebサービスへのAPIアクセスが多数行われ,全体としては分散システムとして動作するものでした。

この問題をチューニングするには,外部へのAPIアクセスがどれだけ発生し,どれぐらいの時間を消費しているのかを把握することがポイントになります。

完全な問題,ベンチマーカ,ブラックボックスを含むリポジトリは,https://github.com/isucon/isucon8-finalで公開されています。本稿における改変を含めたリポジトリは,https://github.com/fujiwara/isucon8-final-wdpress111で公開しています。

注1)
Webアプリケーションのパフォーマンスチューニングコンテストです。

単体アプリケーションへの組込み

まず競技者がチューニングを行う対象であるWebアプリケーションのPerl実装に,X-Rayを導入します。アプリケーションの実行環境でX-Ray daemonを起動し,AWS::XRayと関連モジュールの組込みを数行追加するのみで,アプリケーションのコードに手を入れる必要はありません。

X-Ray daemonを起動する

ISUCON8の初期実装はDocker Composeで提供されています。リポジトリ内のwebapp/docker-compose.yamlに,AWSが提供しているDockerイメージ注2を利用してX-Ray daemonを起動する定義を追加します。

docker-compose.yaml

services:
  isucoin:
    environment:
      (省略)
      AWS_XRAY_DAEMON_ADDRESS: 'xray:2000'
    links:
      - mysql
      - xray
  xray:
    image: amazon/aws-xray-daemon:latest
    command:
      - --local-mode
    environment:
      AWS_REGION: ap-northeast-1
      AWS_ACCESS_KEY_ID: 123456789012
      AWS_SECRET_ACCESS_KEY: xxxxxxxxxxx

競技者がチューニングするWebアプリケーションはisucoinと呼ばれ,コンテナが定義されています。初期状態ではネットワークがブリッジモードのため,アプリケーションからxrayコンテナへ通信するためにはlinksの設定が必要です。環境変数AWS_XRAY_DAEMON_ADDRESSにX-Ray daemonが動作するアドレスとしてxray:2000を指定します。

X-Ray daemonからAWSにトレースを送信するために,xrayコンテナには環境変数AWS_REGION,AWS_ACCESS_KEY_ID,AWS_SECRET_ACCESS_KEY を設定します注3⁠。

注2)
執筆時点ではX-Ray daemon version 3.0.0が含まれていました。
注3)
アクセスキー情報は誤って公開しないよう注意してください。IDの123456789012はサンプルです。
コードにAWS::XRayを組み込む

アプリケーションが起動するエントリポイントであるwebapp/perl/app.psgiファイルに,AWS::XRayと関連モジュールを利用する設定を追加します。やっていることはモジュールをuseして,Plackのミドルウェアをenableしているだけです。太字が追加箇所です。

app.psgi

use Isucoin::Web;
use Devel::KYTProf;
use Devel::KYTProf::Logger::XRay;
use AWS::XRay;
Devel::KYTProf->logger("Devel::KYTProf::Logger::XRay");

my $root_dir = File::Basename::dirname(__FILE__);
my $app = Isucoin::Web->psgi($root_dir);
builder {
  enable 'XRay',
    name => 'isucoin';

モジュールのインストールを行うために,cpanfilerequiresを追加します。

cpanfile

requires 'Devel::KYTProf', '0.9992';
requires 'AWS::XRay', '0.08';
requires 'Plack::Middleware::XRay', '0.06';
requires 'Devel::KYTProf::Logger::XRay', '0.04';

これでAWS::XRayの組込みと,トレースの送信準備ができました。

競技アプリケーションを起動し,ブラウザからアクセスして,isucoinアプリケーションが表示されるのを確認してください。しばらくすると,docker-composeコマンドを実行しているコンソールに,daemonがAWSにトレースを送信しているログが出力されます注4⁠。

docker-composeのログ出力

xray_1     | 2019-04-16T15:16:58Z [Info] Initializing AWS
X-Ray daemon 3.0.0
xray_1     | 2019-04-16T15:18:24Z [Info] Successfully sent
batch of 7 segments (1.432 seconds)

実際の競技時におけるアプリケーションのパフォーマンスを解析するために,リポジトリのREADMEにしたがってベンチマークを実行してみましょう注5⁠。

注4)
xrayコンテナがエラーを出力している場合は,アクセスキーなどの設定を確認してください。
注5)
実行環境にGo 1.11以上が必要です。
X-Ray console による解析

ベンチマークを実行後にX-Ray consoleを見ると,サービスマップが表示されます図1⁠。

図1 サービスマップ

図1 サービスマップ

この画面にはX-Ray daemonが送信したトレースが可視化されています。個々の丸いノードがセグメントで,isucoinからDBI,DBI::st,Furl::HTTPに矢印が伸び,呼び出されているのが見て取れます。

処理の絞り込み

isucoinをクリックすると,そのセグメントの処理に要した時間(レイテンシ)が分布図になって表示されます図2⁠。

図2 isucoinサービスのレイテンシ

図2 isucoinサービスのレイテンシ

ここでレイテンシが3秒以上の遅い処理を選択して「トレースの表示」をクリックすると,条件に該当するトレースの一覧が表示されます。上の欄には3秒以上かかった処理がフィルタリングされ,URLでグループ化されて表示されます。平均レイテンシが3.4秒の/info?cursor=0を選択し図3⁠,そのうちの1つのトレースを開いてみましょう。

図3 処理に3秒以上かかったURLの一覧

図3 処理に3秒以上かかったURLの一覧

著者プロフィール

藤原俊一郎(ふじわらしゅんいちろう)

2011年より面白法人カヤック。技術部SREチームリーダー。ISUCON優勝3回,出題2回。最近の趣味はマネージドサービスの隙間を埋める隙間家具のようなツールをGoで作ってOSSにすること。著書に『みんなのGo言語[現場で使える実践テクニック]』(共著,技術評論社)。

URL:https://sfujiwara.hatenablog.com/