はじめに
自己紹介
未経験からWEB系エンジニアへの転職を目指している者です。現在はRuby on Railsを学習中です。
この記事を書いたきっかけ
現在、プログラミング学習コミュニティでISUCONの勉強会に参加しており、『達人が教えるWebパフォーマンスチューニング〜ISUCONから学ぶ高速化の実践』を読みながら学習を進めています。
ISUCON本を読み進めると3章のハンズオンを取り組むことになるのですが、AWSを初めて使う自分のような初学者には少し難しい内容だったので、備忘録を兼ねて用語と手順をまとめてみました。
動作環境
- mac OS Sonoma 14.2.1
ハンズオンの概要
3章では、iscogramという画像投稿サイトをAWSのEC2で起動させて、パフォーマンスチューニングの流れをハンズオンで実践的に学習していきます。
1.private-isuをAWSのEC2で起動させる
2.負荷試験環境を準備する
3.ベンチマーカーで負荷試験を実行できるようにする
4.ボトルネックを発見する
5.パフォーマンスチューニング
private-isuをAWSのEC2で起動させる
ISUCONの学習用として一般に公開されているリポジトリに記載されているAMI IDを使用してインスタンスを起動させます。
AWSとは
- Amazon Web Servicesの略称
- Amazonが提供するクラウドサービスで仮想サーバー、DB、ストレージなどのさまざまなサービスがある
EC2とは
- Amazon Elastic Compute Cloudの略称
- AWS上に構築できる仮想サーバーのサービス
EC2の公式ドキュメント
AMIとは
- Amazon Machine Imageの略称
- EC2インスタンスを起動するための必要情報がまとめられたテンプレートみたいなやつ
- インスタンスはEC2で構築したサーバーの単位のこと
- インスタンスとAMIの公式ドキュメント
起動手順
- AWSのEC2サービスのページに移動する
- ページ左のナビゲーションバーから"AMI"をクリック
- "パブリックイメージ"を選択して、検索バーにリポジトリで公開されているprivate-isuのAMI ID
ami-0d92a4724cae6f07bを入力して検索 - 検索結果に出てきたイメージのAMI IDをクリック
- "AMIからインスタンス起動"をクリックして、イメージの概要ページに移動する
- インスタンスに適当な名前を付ける
- インスタンスタイプを選択する
- 今回はISUCON本推奨の
C5.largeを使用 - 1時間で約0.1ドルくらいかかるので、長時間起動したままにしないように注意!
インスタンスタイプとは
- 用途によって選択できるCPUやメモリなどの組み合わせのこと
- 当たり前のことではあるが、スペックが高いと料金も高くなる
- インスタンスタイプの公式ドキュメント
- "新しいキーぺエアの作成"をクリック
- キーペアに適当な名前を付ける
- キーペアのタイプとプライベートキーファイル形式の設定はそのまま
- "キーペアを作成"をクリック
キーペアとは
- 公開鍵暗号方式に使われる公開鍵と秘密鍵の組み合わせのこと
- EC2インスタンスへ接続する際のセキュリティ認証に使う
- EC2インスタンスに誰でも接続できないようにするため必要
- キーペアの公式ドキュメント
- 公開鍵暗号方式の解説
- "セキュリティグループを作成"にチェック
- "SSHからのトラフィックを許可"にチェック
- "インターネットからのHTTPトラフィックを許可"にチェック
- 右上の"編集"ボタンをクリック
- SSHとHTTPのソースタイプを"自分のIP"に変更する
SSHとは
- Secure Shellの略称
- 通信を暗号化することで安全にリモートログインできる
- SSHの解説
- ストレージの設定は本で特に指定されていなかったのでデフォルトのまま
- "インスタンスを起動"をクリック
- ロード画面に遷移後、成功と表示されればOK!
動作確認
- 作成したEC2インスタンスの概要ページでパブリックIPアドレスを確認する
- パブリックIPアドレスが
18.177.141.172だった場合、ブラウザでhttp://18.177.141.172/にアクセスする
- iscogramのページが表示されればOK!
- ユーザー登録や画像投稿などの操作をして動作を確認する
負荷試験環境を準備する
nginxにssh接続する
nginxとは
- Webサーバーのソフト
- nginxの公式サイト
インスタンスのパブリックDNSをインスタンスの概要ページからコピーして、ターミナルでsshコマンドを実行する
sshコマンドの解説記事
$ ssh -i <キーペアのパス> <インスタンスのユーザー名>@<インスタンスのパブリックDNS>
# 具体的には以下のようなコマンドとなります
$ ssh -i Downloads/private-isu-keys.pem ubuntu@ec2-18-177-141-172.ap-northeast-1.compute.amazonaws.com
SSHでの接続が拒否された場合は、chmodコマンドでファイルの読み取り権限を付与してから再接続する
chmodコマンドの解説
$ chmod 400 <キーペアのパス>
接続に成功すると、以下のように表示される
Welcome to Ubuntu 22.04.3 LTS (GNU/Linux 6.2.0-1011-aws x86_64)
* Documentation: https://help.ubuntu.com
* Management: https://landscape.canonical.com
* Support: https://ubuntu.com/advantage
System information as of Tue Mar 5 15:17:06 JST 2024
System load: 0.0 Processes: 108
Usage of /: 50.7% of 15.32GB Users logged in: 0
Memory usage: 19% IPv4 address for ens5: 172.31.34.76
Swap usage: 0%
Expanded Security Maintenance for Applications is not enabled.
0 updates can be applied immediately.
Enable ESM Apps to receive additional future security updates.
See https://ubuntu.com/esm or run: sudo pro status
The list of available updates is more than a week old.
To check for new updates run: sudo apt update
Last login: Sun Sep 17 14:52:00 2023 from 153.240.10.3
ubuntu@ip-172-31-34-76:~$
nginxのアクセスログをJSON形式で出力する
vimコマンドでnginx.cnfを開き、httpコンテキストに以下の設定を追加する
vimコマンドの解説
nginx.confの解説
$ sudo vim /etc/nginx/nginx.conf
nginx.cnfに追加する設定
http {
##
# Logging Settings
##
# 変数の解説はISUCON本のp59,60に掲載されています
# --- ここから ---
log_format json escape=json '{ "time":"$time_iso8601",'
'"host":"$remote_addr",'
'"port":"$remote_port",'
'"method":"$request_method",'
'"uri":"$request_uri",'
'"status":"$status",'
'"body_bytes":"$body_bytes_sent",'
'"referer":"$http_referer",'
'"ua":"$http_user_agent",'
'"request_time":"$request_time",'
'"response_time":"$upstream_response_time"}';
access_log /var/log/nginx/access.log json;
# --- ここまで ---
error_log /var/log/nginx/error.log;
}
nginxコマンドで設定ファイルの検証を実行する
nginxコマンドの解説
$ sudo nginx -t
JSON形式となっていない古いログを削除する
JSONとは
- JavaScript Object Notationの略称
- データフォーマットの一種
- JSONの解説
$ sudo rm /var/log/nginx/access.log
nginxをリロードし、設定を再読み込みする
$ sudo systemctl reload nginx
ベンチマーカーで負荷試験を実行できるようにする
EC2上のubuntuにalpをインストールする
以下のコマンドを実行してalpをインストールする
# 記事作成時にlatestであったv1.0.21をダウンロード
$ wget https://github.com/tkuchiki/alp/releases/download/v1.0.21/alp_linux_amd64.tar.gz
$ tar xvzf alp_linux_amd64.tar.gz
# インストール
$ sudo install ./alp /usr/local/bin
動作確認のため、標準入力からJSONのログを与えてalpコマンドでログを解析してみる
$ cat /var/log/nginx/access.log | alp json
以下のようなログ出力結果が出ればOK!
+-------+-----+-----+-----+-----+-----+--------+------------------+-------+-------+--------+-------+-------+-------+-------+--------+-------------+-------------+-------------+-------------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX | METHOD | URI | MIN | MAX | SUM | AVG | P90 | P95 | P99 | STDDEV | MIN(BODY) | MAX(BODY) | SUM(BODY) | AVG(BODY) |
+-------+-----+-----+-----+-----+-----+--------+------------------+-------+-------+--------+-------+-------+-------+-------+--------+-------------+-------------+-------------+-------------+
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /posts/10000 | 0.068 | 0.068 | 0.068 | 0.068 | 0.068 | 0.068 | 0.068 | 0.000 | 1306.000 | 1306.000 | 1306.000 | 1306.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/10000.png | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 1056749.000 | 1056749.000 | 1056749.000 | 1056749.000 |
| 20 | 0 | 20 | 0 | 0 | 0 | GET | / | 1.472 | 1.492 | 29.600 | 1.480 | 1.484 | 1.488 | 1.492 | 0.005 | 35644.000 | 35644.000 | 712880.000 | 35644.000 |
+-------+-----+-----+-----+-----+-----+--------+------------------+-------+-------+--------+-------+-------+-------+-------+--------+-------------+-------------+-------------+-------------+
MacでApacheBenchを使えるようにする
以下のコマンドを実行し、httpdをインストールする
ApacheBenchとは
- Apache HTTP Serverに同梱されている性能テストツール
- abコマンドで単一かつ同一のURLに対するリクエストを、指定した分だけ生成することができる
- ApacheBenchの解説
$ brew install httpd
動作確認のため、abコマンドでiscogramに1並列で10回のリクエストを送信してみる
$ ab -c 1 -n 10 http://EC2のパブリックIP/
以下のようなログ出力結果が出ればOK!
This is ApacheBench, Version 2.3 <$Revision: 1903618 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/
Benchmarking 54.249.70.244 (be patient).....done
Server Software: nginx/1.18.0
Server Hostname: 54.249.70.244
Server Port: 80
Document Path: /
Document Length: 35644 bytes
Concurrency Level: 1
Time taken for tests: 16.201 seconds
Complete requests: 10
Failed requests: 0
Total transferred: 360160 bytes
HTML transferred: 356440 bytes
Requests per second: 0.62 [#/sec] (mean)
Time per request: 1620.087 [ms] (mean)
Time per request: 1620.087 [ms] (mean, across all concurrent requests)
Transfer rate: 21.71 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 22 24 1.8 23 29
Processing: 1522 1596 38.0 1614 1625
Waiting: 1499 1572 37.8 1588 1601
Total: 1545 1620 38.4 1636 1654
Percentage of the requests served within a certain time (ms)
50% 1636
66% 1639
75% 1643
80% 1644
90% 1654
95% 1654
98% 1654
99% 1654
100% 1654 (longest request)
abコマンドの結果とalpによる解析結果を比較する
＜abコマンドの結果＞
abコマンドの動作確認のためiscogramへ10回リクエストした結果から、レスポンスタイムの平均値は1620[ms]
Time per request: 1620.087 [ms] (mean)
＜alpによる解析＞
nginxのアクセスログの末尾10件をalpコマンドで解析するとレスポンスタイムの平均値は1475[ms]
$ tail -n 10 /var/log/nginx/access.log | alp json -o count,method,uri,min,avg,max
# 解析結果
+-------+--------+-----+-------+-------+-------+
| COUNT | METHOD | URI | MIN | AVG | MAX |
+-------+--------+-----+-------+-------+-------+
| 10 | GET | / | 1.468 | 1.475 | 1.484 |
+-------+--------+-----+-------+-------+-------+
レスポンスタイムの計測値を比較すると145[ms]の差があるが、これはEC2サーバーで処理を終えた結果がクライアントに届くまでに時間がかかるためだと考えられる
アクセスログのローテーション方法
＜ログのローテート＞
複数回の試験結果を1つのログファイルに記録してしまうとalpでの解析が面倒になるため、負荷試験ごとにログファイルを変更する必要がある
＜ローテートの手順＞
nginxのログファイルをリネームする
$ sudo mv /var/log/nginx/access.log //var/log/nginx/access.log.old
nginxをリロードし、新しいファイルにログが出力されるようにする
$ sudo systemctl reload nginx
ボトルネックを発見する
最初の状態で負荷試験を実行する
Macでabコマンドを実行し、1並列で30[s]間リクエストを送る
$ ab -c 1 -t 30 http://EC2のパブリックIP/
# 実行結果
This is ApacheBench, Version 2.3 <$Revision: 1903618 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/
Benchmarking 35.77.89.45 (be patient)
Finished 19 requests
Server Software: nginx/1.18.0
Server Hostname: 35.77.89.45
Server Port: 80
Document Path: /
Document Length: 35644 bytes
Concurrency Level: 1
Time taken for tests: 30.458 seconds
Complete requests: 19
Failed requests: 0
Total transferred: 684304 bytes
HTML transferred: 677236 bytes
Requests per second: 0.62 [#/sec] (mean)
Time per request: 1603.031 [ms] (mean)
Time per request: 1603.031 [ms] (mean, across all concurrent requests)
Transfer rate: 21.94 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 22 23 1.3 23 27
Processing: 1532 1580 41.7 1593 1648
Waiting: 1508 1554 40.1 1568 1624
Total: 1555 1603 42.0 1616 1675
Percentage of the requests served within a certain time (ms)
50% 1615
66% 1638
75% 1638
80% 1639
90% 1659
95% 1675
98% 1675
99% 1675
100% 1675 (longest request)
ベンチマーク実行中にEC2でtopコマンドを実行して、システム全体の負荷を確認する
topコマンドの解説
$ top
# 実行結果
top - 14:05:32 up 1:07, 2 users, load average: 0.40, 0.15, 0.05
Tasks: 108 total, 1 running, 107 sleeping, 0 stopped, 0 zombie
%Cpu(s): 45.2 us, 0.3 sy, 0.0 ni, 54.5 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
MiB Mem : 3695.7 total, 1582.2 free, 688.2 used, 1425.3 buff/cache
MiB Swap: 0.0 total, 0.0 free, 0.0 used. 2769.2 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
818 mysql 20 0 1786676 450964 36352 S 87.3 11.9 1:38.44 mysqld
844 isucon 20 0 222216 72920 9984 S 3.3 1.9 0:03.35 ruby
422 _chrony 20 0 18892 3612 2944 S 0.3 0.1 0:00.08 chronyd
実行結果から読み取れること
- 3行目:
%Cpu(s): 45.2 usはホストで使えるすべてのCPUコア(c5.largeは2コア)を合計したものを100とした場合の使用率を示しており、約45[%]のリソースが使われている - 7行目：
%CPU:の項目からMySQLのプロセスは約87[%]ものリソースを使っている(CPU1コア換算) - 8行目：
%CPU:の項目からWebアプリケーションのプロセスは約3[%]しかリソースを使っていない(CPU1コア換算)
これらの結果から、MySQLの処理がボトルネックになっていることと、ホスト全体で2コアのCPUが使えるにもかかわらず、1コア分は遊んでいることがわかる
MySQLのボトルネック原因を調査する
MySQLで発行されているクエリを解析して、ボトルネックとなっている原因の詳細を調査する
＜スロークエリログ＞
MySQLでは、処理に時間がかかったクエリをスロークエリログに出力することができる
スロークエリログの解説
記録される情報は下記の通り
- 処理したSQL文
- Query_time:クエリの処理にかかった時間
- Lock_time:ロックを取得する時間
- Rows_sent:クエリの実行結果とクライアントに送信した行数
- Rows_examined:クエリを読み取るためにSQL内部で読み取った行数
＜スロークエリログの出力設定＞
vimコマンドでmysqld.cnfを開き、以下の設定を追加する
$ sudo vim /etc/mysql/mysql.conf.d/mysqld.cnf
mysqld.cnfに追加する設定
# Here you can see queries with especially long duration
slow_query_log = 1
slow_query_log_file = /var/log/mysql/mysql-slow.log
long_query_time = 0
mysqlを再起動させる
$ sudo systemctl restart mysql
＜スロークエリログの解析＞
ベンチマークを再度実行する
$ ab -c 1 -t 30 http://EC2のパブリックIP/
mysqldumpslowコマンドを実行して、スロークエリログのサマリーを出力する
mysqldumpslowコマンドの解説
$ sudo mysqldumpslow /var/log/mysql/mysql-slow.log
# 実行結果
Reading mysql slow query log from /var/log/mysql/mysql-slow.log
Count: 418 Time=0.05s (19s) Lock=0.00s (0s) Rows=3.0 (1254), isuconp[isuconp]@localhost
SELECT * FROM `comments` WHERE `post_id` = N ORDER BY `created_at` DESC LIMIT N
Count: 19 Time=0.02s (0s) Lock=0.00s (0s) Rows=10000.0 (190000), isuconp[isuconp]@localhost
SELECT `id`, `user_id`, `body`, `created_at`, `mime` FROM `posts` ORDER BY `created_at` DESC
Count: 418 Time=0.02s (6s) Lock=0.00s (0s) Rows=1.0 (418), isuconp[isuconp]@localhost
SELECT COUNT(*) AS `count` FROM `comments` WHERE `post_id` = N
Count: 1 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), isuconp[isuconp]@localhost
SET NAMES utf8mb4
Count: 1672 Time=0.00s (0s) Lock=0.00s (0s) Rows=1.0 (1672), isuconp[isuconp]@localhost
SELECT * FROM `users` WHERE `id` = N
Count: 4763 Time=0.00s (0s) Lock=0.00s (0s) Rows=4583.3 (21830024), isuconp[isuconp]@localhost
#
Count: 2255 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), 0users@0hosts
administrator command: Close stmt
Count: 2508 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), 0users@0hosts
administrator command: Prepare
一番の多くの時間を消費しているクエリがサマリーの一番上に出力される
以下のログより、SELECT文が30秒間に418回呼ばれて、計19秒も消費していることがわかる
Count: 418 Time=0.05s (19s) Lock=0.00s (0s) Rows=3.0 (1254), isuconp[isuconp]@localhost
SELECT * FROM `comments` WHERE `post_id` = N ORDER BY `created_at` DESC LIMIT N
lessコマンドでmysqld.cnfを開き、一番の多くの時間を消費しているクエリの詳細を確認する
lessコマンドの解説
sudo less /var/log/mysql/mysql-slow.log
発行されているクエリの詳細を見てみる
# Query_time: 0.046435 Lock_time: 0.000001 Rows_sent: 3 Rows_examined: 100003
SET timestamp=1709704605;
SELECT * FROM `comments` WHERE `post_id` = 9999 ORDER BY `created_at` DESC LIMIT 3;
Rows_sent: 3 Rows_examined: 100003より、クエリを処理する際に内部で読み取ったテーブルの行数は100003行に対し、クライアントに返した行数は3行であることがわかる
なぜ、こんな非効率な処理となっているか原因を探るため、commentsテーブルの詳細を確認する
MySQLサーバーにログイン
$ sudo mysql -u root
isuconpのDBを選択
$ USE isuconp;
commentsテーブルのスキーマを表示すると、プライマリキー以外のインデックスがないことがわかる
$ SHOW CREATE TABLE comments;
# 出力結果
+----------+----------------------------------------------------------------------------+
| Table | Create Table |
+----------+----------------------------------------------------------------------------+
| comments | CREATE TABLE `comments` (
`id` int NOT NULL AUTO_INCREMENT,
`post_id` int NOT NULL,
`user_id` int NOT NULL,
`comment` text NOT NULL,
`created_at` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP,
PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=100001 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci|
+----------+----------------------------------------------------------------------------+
1 row in set (0.00 sec)
EXPLAIN文でクエリの実行計画を確認してみる
EXPLAIN文の解説
$ EXPLAIN SELECT * FROM `comments` WHERE `post_id` = 9999 ORDER BY `created_at` DESC LIMIT 3;
+----+-------------+----------+------------+------+---------------+------+---------+------+-------+----------+-----------------------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+----------+------------+------+---------------+------+---------+------+-------+----------+-----------------------------+
| 1 | SIMPLE | comments | NULL | ALL | NULL | NULL | NULL | NULL | 96610 | 10.00 | Using where; Using filesort |
+----+-------------+----------+------------+------+---------------+------+---------+------+-------+----------+-----------------------------+
1 row in set, 1 warning (0.00 sec)
keyの値がNULLになっているのでインデックスは使用されず、commentsテーブルほぼすべてのレコードを読み取ろうとしていることがわかり、インデックスを作成すれば改善が見込めそうだという推測ができる
インデックスと実行計画の解説
パフォーマンスチューニング
パフォーマンスチューニングを実施する
post_idカラムにインデックスを貼る
インデックスを追加するSQLの解説
$ ALTER TABLE comments ADD INDEX index_post_id (post_id);
もう一度EXPLAIN文を実行する
$ EXPLAIN SELECT * FROM `comments` WHERE `post_id` = 9999 ORDER BY `created_at` DESC LIMIT 3;
+----+-------------+----------+------------+------+---------------+---------------+---------+-------+------+----------+----------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+----------+------------+------+---------------+---------------+---------+-------+------+----------+----------------+
| 1 | SIMPLE | comments | NULL | ref | index_post_id | index_post_id | 4 | const | 11 | 100.00 | Using filesort |
+----+-------------+----------+------------+------+---------------+---------------+---------+-------+------+----------+----------------+
1 row in set, 1 warning (0.00 sec)
keyの値からindex_post_idというインデックスが使用されることがわかり、rowsの値から11行程度の読み取りで処理できる見込みであることがわかる
再度、クエリを実行する
$ SELECT * FROM `comments` WHERE `post_id` = 9999 ORDER BY `created_at` DESC LIMIT 3;
スロークエリログを確認すると、14行の読み取りで処理できるようになっていることがわかる
$ sudo less /var/log/mysql/mysql-slow.log
# Query_time: 0.000340 Lock_time: 0.000003 Rows_sent: 3 Rows_examined: 14
SET timestamp=1709708074;
SELECT * FROM `comments` WHERE `post_id` = 9999 ORDER BY `created_at` DESC LIMIT 3;
パフォーマンスチューニングの成果を確認する
スロークエリログを削除し、nginxを再起動する
$ sudo rm /var/log/nginx/access.log
$ sudo systemctl restart nginx
abコマンド実行する
$ ab -c 1 -t 30 http://EC2のパブリックIP/
# 実行結果
This is ApacheBench, Version 2.3 <$Revision: 1903618 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/
Benchmarking 35.77.89.45 (be patient)
Finished 199 requests
Server Software: nginx/1.18.0
Server Hostname: 35.77.89.45
Server Port: 80
Document Path: /
Document Length: 35644 bytes
Concurrency Level: 1
Time taken for tests: 30.036 seconds
Complete requests: 199
Failed requests: 0
Total transferred: 7167184 bytes
HTML transferred: 7093156 bytes
Requests per second: 6.63 [#/sec] (mean)
Time per request: 150.934 [ms] (mean)
Time per request: 150.934 [ms] (mean, across all concurrent requests)
Transfer rate: 233.03 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 21 23 0.9 23 29
Processing: 122 128 7.7 127 212
Waiting: 98 103 7.3 102 189
Total: 144 151 8.2 150 242
Percentage of the requests served within a certain time (ms)
50% 150
66% 151
75% 152
80% 152
90% 154
95% 157
98% 171
99% 195
100% 242 (longest request)
abコマンド実行中にtopコマンドを実行する
$ top
# 実行結果
top - 16:21:41 up 0 min, 1 user, load average: 0.61, 0.20, 0.07
Tasks: 113 total, 1 running, 112 sleeping, 0 stopped, 0 zombie
%Cpu(s): 25.6 us, 4.4 sy, 0.0 ni, 69.8 id, 0.0 wa, 0.0 hi, 0.0 si, 0.2 st
MiB Mem : 3695.7 total, 2633.4 free, 637.6 used, 424.6 buff/cache
MiB Swap: 0.0 total, 0.0 free, 0.0 used. 2827.2 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
661 isucon 20 0 217928 68952 9984 S 33.9 1.8 0:09.59 ruby
523 mysql 20 0 1784704 420432 36096 S 25.6 11.1 0:08.29 mysqld
888 ubuntu 20 0 10936 3840 3200 R 0.7 0.1 0:00.04 top
インデックスを貼る前と貼った後のデータを比較してみる
| 項目 | インデックスなし | インデックスあり |
|---|---|---|
| 全体のCPU使用率 | 45.2[%] | 25.6[%] |
| MySQLのCPU使用率(1コア換算) | 87.3[%] | 25.6[%] |
| WebアプリのCPU使用率(1コア換算) | 3.3[%] | 33.9[%] |
| レイテンシ | 1603[ms] | 151[ms] |
| スループット | 0.62[request/sec] | 6.63[request/sec] |
私の環境ではインデックスを貼ることで約10倍のリクエストを処理できるようになり、MySQLのCPU使用率も約60[%]下がったので、はじめてのパフォーマンスチューニング成功です!
しかし、ISUCON本では約50倍のリクエストを処理できるようになっていたので、それと比較すると劣った結果でした。
abコマンドの結果がサーバーとクライアントの通信経路で発生しているレイテンシも含んでおり、私の環境ではこれが影響しているのではないかと考えましたが、pingコマンドを実行してもレイテンシは平均25[ms]くらいで直接的な原因ではなさそうでした。
沼りそうなので、今回はこれ以上の深掘りはやめておきますw
pingコマンドの解説
EC2にpingを送る方法の解説
まとめ
初めて使うツールやコマンドだらけでかなり苦労しましたが、なんとかパフォーマンスチューニングすることができました。
自分が詰まったところには、公式ドキュメントや記事のリンクを貼っているので初学者の参考になれば幸いです。
ISUCON本の3章では、並列処理についてパフォーマンスチューニングのハンズオンも行っているで今後はそちらの記事も作成できればと考えています。
=>続編作成しました！
ISUCON本で初めてのパフォーマンスチューニングに挑戦してみた ~続編~
最後までお読みいただきありがとうございます！