ISUCON本で初めてのパフォーマンスチューニングに挑戦してみた ~続編~

はじめに

この記事は『ISUCON本で初めてのパフォーマンスチューニングに挑戦してみた』の続編です。

ハンズオンの概要

前回の記事ではcommentsテーブルにindexを貼ることで、ボトルネックとなっていたMySQLの処理を軽くすることに成功しました。
今回は、並列処理に着目してパフォーマンスチューニングを行います。

1.ベンチマーカーの並列度を上げる
2.サーバーの並列度を上げる
3.パフォーマンスチューニングの成果を確認する

ベンチマーカーの並列度を上げる

ベンチマーカーの並列度を上げて試験結果を比較する

まず、abコマンドで直列にリクエストを送信する負荷試験を実行する。
ApacheBenchの解説

＜1クライアントからの直列リクエスト＞

$ ab -c 1 -t 30 http://EC2のパブリックIP/

実行結果の抜粋
Requests per second:    6.62 [#/sec] (mean)
Time per request:       151.133 [ms] (mean)

次に、abコマンドの-cオプションの値を変更して、複数のクライアントが同時にリクエストを送信する負荷試験を実行する。
＜2クライアントからの並列リクエスト＞

$ ab -c 2 -t 30 http://EC2のパブリックIP/

実行結果の抜粋
Requests per second:    12.26 [#/sec] (mean)
Time per request:       163.112 [ms] (mean)

＜3クライアントからの並列リクエスト＞

$ ab -c 3 -t 30 http://EC2のパブリックIP/

実行結果の抜粋
Requests per second:    12.69 [#/sec] (mean)
Time per request:       236.401 [ms] (mean)

＜4クライアントからの並列リクエスト＞

$ ab -c 4 -t 30 http://EC2のパブリックIP/

実行結果の抜粋
Requests per second:    12.66 [#/sec] (mean)
Time per request:       315.865 [ms] (mean)

負荷試験の結果を比較しやすいように表にまとめる。

クライアント数	レイテンシ[ms]	スループット[request/sec]
1	151.1	6.62
2	163.1	12.26
3	236.4	12.69
4	315.9	12.66

上の表から次のことがわかる。

• スループットは並列度2で頭打ちとなっている
• レイテンシは並列度2までほぼ変化ないが、並列度が3以上では悪化する

そして、結果から以下のことが考察できる。

• 並列度2まではサーバーの処理能力が足りている
• 並列度3以上ではサーバーの処理能力が飽和してレイテンシが悪化している

サーバーの処理能力を全て使えているか確認する

現状、並列度3以上ではサーバーの処理能力を使い切っているように見えるが、処理能力に余裕があるもののリソースを効率的に利用できていない場合は改善の余地がある。
そこで、次は並列度とCPUの使用率の関係を調べてみる。
前回の記事ではtopコマンドを使ってCPU使用率を見たが、今回は時系列でCPU使用率を観察できるdstatコマンドを使う。

dstat公式リポジトリ
dstatコマンドの解説

まず、EC2上のubuntuにdstatをインストールする。

$ sudo apt install dstat

CPU使用率はdstat --cpuで見ることができる。解除はCtrl　+　C。

$ dstat --cpu

#  実行結果
--total-cpu-usage--
usr sys idl wai stl
  3   1  92   5   0
  0   0 100   0   0
  0   0 100   0   0

dstatコマンド実行中した状態で、並列度を変えてabコマンドを実行しCPU使用率を観察する。
先ほどの表にCPU使用率の列を追加すると以下のようになる。

クライアント数	レイテンシ[ms]	スループット[request/sec]	usrのCPU使用率[%]	sysのCPU使用率[%]
1	151.1	6.62	25	4
2	163.1	12.26	49	7
3	236.4	12.69	50	6
4	315.9	12.66	49	6

上の表から次のことがわかる。

• CPU使用率は並列度2で頭打ちとなっている
• CPU使用率は最大で計56[%]となっているので、約1コア弱のCPUが稼働していない

そして、結果から以下のことが考察できる。

• 遊んでいるCPUを有効に活用できれば、パフォーマンスの向上が期待できるのではないか？

サーバーの並列度を上げる

CPUのリソースを使いきれていない原因を特定する

abコマンドを並列度4で実行している状態で、topコマンドを実行する。

$ top

# 実行結果
top - 15:32:14 up 49 min,  1 user,  load average: 0.55, 0.39, 0.20
Tasks: 108 total,   3 running, 105 sleeping,   0 stopped,   0 zombie
%Cpu(s): 50.1 us,  6.1 sy,  0.0 ni, 43.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
MiB Mem :   3695.7 total,   1759.8 free,    668.6 used,   1267.3 buff/cache
MiB Swap:      0.0 total,      0.0 free,      0.0 used.   2795.3 avail Mem 

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND                     
    854 isucon    20   0  222572  74904   9984 R  63.0   2.0   2:32.78 ruby                        
   1462 mysql     20   0 1784704 422268  36352 S  48.0  11.2   1:56.28 mysqld                      
    402 memcache  20   0  413424   7424   3712 R   0.3   0.2   0:00.78 memcached  

COMMANDの項目を見ると1番目がRubyのプロセスで、2番目がMySQLのプロセスであることがわかる。
systemctlコマンドで稼働しているアプリケーションプロセスの状況を確認する。
systemctlコマンドの解説

$ systemctl status isu-ruby

# 実行結果
● isu-ruby.service - isu-ruby
     Loaded: loaded (/etc/systemd/system/isu-ruby.service; enabled; vendor preset: enabled)
     Active: active (running) since Fri 2024-03-08 14:43:15 JST; 56min ago
   Main PID: 401 (ruby)
      Tasks: 3 (limit: 4416)
     Memory: 94.1M
        CPU: 3min 5.764s
     CGroup: /system.slice/isu-ruby.service
             ├─401 "unicorn master -c unicorn_config.rb" "" "" "" "" "" "" "" "" "" "" "" "" "" "" "">
             └─854 "unicorn worker[0] -c unicorn_config.rb" "" "" "" "" "" "" "" "" "" "" "" "" "" "">

実行結果から、unicorn masterという親プロセスと、unicorn woker[0]という子プロセスが動作していることがわかる。

unicornとは

• アプリケーションサーバーライブラリの一種
• Rubyで実装されたWebアプリケーションであるiscogramをHTTPサーバーとして動かすために使われている
• unicornはmasterという親プロセスから、複数のworkerプロセスという実際のリクエスト処理を行う子プロセスを起動するアーキテクチャになっている
• unicorn公式ページ
• unicornの解説

子プロセスが1つしか稼働していないということは、同時に複数のリクエストが来たとしても、リクエストは順番に1つずつしか処理することができず、後から来たリクエストに待ち時間が発生してしまう。

よって、サーバーに複数のCPUが搭載されていてもソフトウェアのアーキテクチャが原因でCPUのリソースが有効に使えていないことがわかった。

複数のCPUを有効に使用できるように設定する

unicornの設定ファイルは/home/isucon/private_isu/webapp/ruby/unicorn_config.rbにあるので、vimコマンドで設定を変更する。

$ sudo vim /home/isucon/private_isu/webapp/ruby/unicorn_config.rb

プロセス数はworker_processesという項目で変更できる。
プロセス数 = CPU数　* 2とするのが一般的であるので、今回もそれに習ってプロセス数を4に変更する。（c5.largeインスタンスは2CPUのため）

# unicorn_config.rbの設定

worker_processes 4
preload_app true
listen "0.0.0.0:8080"

設定を反映するため、アプリケーションを再起動する。

$ sudo systemctl restart isu-ruby

再度、稼働しているアプリケーションプロセスの状況を確認する。

$ systemctl status isu-ruby

# 実行結果
● isu-ruby.service - isu-ruby
     Loaded: loaded (/etc/systemd/system/isu-ruby.service; enabled; vendor preset: enabled)
     Active: active (running) since Fri 2024-03-08 15:46:48 JST; 45s ago
   Main PID: 2489 (ruby)
      Tasks: 5 (limit: 4416)
     Memory: 46.2M
        CPU: 338ms
     CGroup: /system.slice/isu-ruby.service
             ├─2489 "unicorn master -c unicorn_config.rb" "" "" "" "" "" "" "" "" "" "" "" "" "" "" ">
             ├─2491 "unicorn worker[0] -c unicorn_config.rb" "" "" "" "" "" "" "" "" "" "" "" "" "" ">
             ├─2492 "unicorn worker[1] -c unicorn_config.rb" "" "" "" "" "" "" "" "" "" "" "" "" "" ">
             ├─2493 "unicorn worker[2] -c unicorn_config.rb" "" "" "" "" "" "" "" "" "" "" "" "" "" ">
             └─2494 "unicorn worker[3] -c unicorn_config.rb" "" "" "" "" "" "" "" "" "" "" "" "" "" ">

unicorn worker[0] からunicorn worker[3] まで、計4つの子プロセスが実行されていることがわかる。

パフォーマンスチューニングの成果を確認する

再度、dstatコマンド実行中した状態で並列度を変えてabコマンドを実行しCPU使用率を観察すると以下の結果が得られた。

クライアント数	レイテンシ[ms]	スループット[request/sec]	usrのCPU使用率[%]	sysのCPU使用率[%]
1	150.9	6.62	26	2
2	156.8	12.75	53	6
3	220.7	13.59	78	9
4	281.3	14.22	90	9

workerプロセスを増やしたことによる改善結果

• 並列度4でのCPU使用率は最大で計99[%]となっていることから、2コア全てのリソースが使えるようになった
• 並列度4でのスループットは12.66から14.22と約12[%]向上した

前回の記事と同様に、ISUCON本と比較すると劣った結果ではありますが改善されていることが確認できました!

まとめ

今回のハンズオンを通して、ISUCONに挑戦するには幅広い知識が必要なことを痛感しました...
ただ、その分得られるものが多く、やりがいもあるので地道に学習していきたいと思います。
まだまだ先は長いですが、引き続き日々の学びをアウトプットできるよう頑張りたいです。
前回の記事に引き続き最後まで読んでいただいた方、ありがとうございました!