Zenn
✨

R-ISUCONN 2022 write-up

2023/08/25に公開
Go
ISUCON
tech

環境構築

Git

https://github.com/recruit-tech/RISUCON2022Summer/tree/main
構築手順は以下にあったがMac向け、自分の環境はWindowsなので
VagrantでUbuntu20.04のVMを構築しansibleを流して構築した
https://github.com/recruit-tech/RISUCON2022Summer/blob/main/infra/virtual-machine/README.md

80番ポートをホスト：ゲストでポートフォワードすると以下のようなページが見える
http://localhost:80

初期スコア:133

isucon@ubuntu2004:~/r-isucon/bench$ ./bin/bench -target http://localhost
07:15:13.011126 Language: go
07:15:13.011282 Reason: 負荷走行に成功しました
07:15:13.011312 Score: 133
07:15:13.011315 Load Level: 1
07:15:13.011341
07:15:13.011342 Critical Error count: 0
07:15:13.011344
07:15:13.011345 Application Error count: 0
07:15:13.011347
07:15:13.011348 Trivial Error count: 0
{
  "pass": true,
  "score": 133,
  "messages": [
    "Report ID: 2a33043a-c4f9-4358-8b5e-17343d2c5884",
    "負荷走行に成功しました",
    "Load Level: 1"
  ]
}
{
  "pass": true,
  "score": 133,
  "messages": [
    "Report ID: 2a33043a-c4f9-4358-8b5e-17343d2c5884",
    "負荷走行に成功しました",
    "Load Level: 1"
  ]
}

alp / pt-query-digestの設定

  • alpのインストール
wget https://github.com/tkuchiki/alp/releases/download/v1.0.12/alp_linux_amd64.tar.gz`
tar -xvf alp_linux_amd64.tar.gz
sudo install alp /usr/local/bin/alp
  • alpのconfigファイル作成
isucon@ubuntu2004:~/r-isucon/bench$ cat config.yml
sort: sum                      # max|min|avg|sum|count|uri|method|max-body|min-body|avg-body|sum-body|p1|p50|p99|stddev
reverse: true                   # boolean
query_string: true              # boolean
output: count,5xx,method,uri,min,max,sum,avg,p99                    # string(comma separated)

matching_groups:            # array
  - /login
  - /schedule
  - /user/icon
  - /calendar
  - /logout
  - /user
  • slow query logの設定
vi /etc/mysql/mariadb.conf.d/50-server.cnf
[mysqld]
slow_query_log = 1
slow_query_log_file = /var/log/mysql/slow.log
long_query_time = 0
  • ログローテーション用のスクリプト作成
#!/bin/bash

# ログファイルのパス
nginx_log_path="/var/log/nginx/access.log"
mysql_log_path="/var/log/mysql/slow.log"

# ローテーション
sudo mv "$nginx_log_path" "$nginx_log_path.$(date +'%Y%m%d%H%M%S').bak"
sudo mv "$mysql_log_path" "$mysql_log_path.$(date +'%Y%m%d%H%M%S').bak"

# ログファイルの再作成
sudo touch "$nginx_log_path"
sudo touch "$mysql_log_path"

# NginxとMySQLのリスタート
sudo service nginx restart
sudo service mariadb restart
  • alp結果
isucon@ubuntu2004:~/r-isucon/bench$ sudo alp ltsv --file=/var/log/nginx/access.log --config=./config.yml
+-------+-----+--------+-------------+-------+-------+---------+-------+-------+
| COUNT | 5XX | METHOD |     URI     |  MIN  |  MAX  |   SUM   |  AVG  |  P99  |
+-------+-----+--------+-------------+-------+-------+---------+-------+-------+
| 202   | 0   | POST   | /login      | 0.004 | 1.688 | 107.620 | 0.533 | 1.569 |
| 658   | 0   | PUT    | /schedule   | 0.008 | 1.481 | 54.683  | 0.083 | 0.840 |
| 250   | 0   | GET    | /calendar   | 0.004 | 1.436 | 36.959  | 0.148 | 1.052 |
| 43    | 0   | POST   | /user       | 0.008 | 1.600 | 31.450  | 0.731 | 1.600 |
| 295   | 0   | GET    | /schedule   | 0.008 | 0.849 | 15.486  | 0.052 | 0.672 |
| 138   | 0   | POST   | /schedule   | 0.016 | 1.545 | 14.202  | 0.103 | 1.236 |
| 741   | 0   | GET    | /user/icon  | 0.004 | 0.540 | 10.132  | 0.014 | 0.056 |
| 1026  | 0   | GET    | /user       | 0.000 | 0.584 | 5.526   | 0.005 | 0.020 |
| 114   | 0   | GET    | /me         | 0.004 | 0.140 | 1.124   | 0.010 | 0.108 |
| 228   | 0   | POST   | /logout     | 0.000 | 0.100 | 0.714   | 0.003 | 0.020 |
| 1     | 0   | POST   | /initialize | 0.184 | 0.184 | 0.184   | 0.184 | 0.184 |
| 4     | 0   | PUT    | /me/icon    | 0.044 | 0.061 | 0.157   | 0.039 | 0.061 |
| 3     | 0   | PUT    | /me         | 0.012 | 0.016 | 0.028   | 0.009 | 0.016 |
+-------+-----+--------+-------------+-------+-------+---------+-------+-------+

→まずは最も遅いPOST /login を改善する

POST /loginの改善:（133->313）

login時のセッションID生成のコードの効率が悪いため改善する

isucon@ubuntu2004:~/r-isucon/bench$ ulimit -u 1024 && ./bin/bench -target http://localhost
07:32:34.256547 Language: go
07:32:34.256569 Reason: 負荷走行に成功しました
07:32:34.256578 Score: 313
07:32:34.256580 Load Level: 1
07:32:34.256584
07:32:34.256585 Critical Error count: 0
07:32:34.256587
07:32:34.256588 Application Error count: 0
07:32:34.256593
07:32:34.256594 Trivial Error count: 0
{
  "pass": true,
  "score": 313,
  "messages": [
    "Report ID: 58972996-df74-4eb8-a308-62c9164a501f",
    "負荷走行に成功しました",
    "Load Level: 1"
  ]
}
{
  "pass": true,
  "score": 313,
  "messages": [
    "Report ID: 58972996-df74-4eb8-a308-62c9164a501f",
    "負荷走行に成功しました",
    "Load Level: 1"
  ]
}

isucon@ubuntu2004:~/r-isucon/bench$ sudo alp ltsv --file=/var/log/nginx/access.log --config=./config.yml
+-------+-----+--------+-------------+-------+-------+---------+-------+-------+
| COUNT | 5XX | METHOD |     URI     |  MIN  |  MAX  |   SUM   |  AVG  |  P99  |
+-------+-----+--------+-------------+-------+-------+---------+-------+-------+
| 531   | 0   | GET    | /calendar   | 0.004 | 5.281 | 116.634 | 0.220 | 0.752 |
| 971   | 0   | PUT    | /schedule   | 0.020 | 6.175 | 58.911  | 0.061 | 0.124 |
| 653   | 0   | GET    | /schedule   | 0.012 | 0.268 | 21.808  | 0.033 | 0.068 |
| 253   | 0   | POST   | /schedule   | 0.024 | 6.091 | 18.558  | 0.073 | 0.332 |
| 2165  | 0   | GET    | /user       | 0.004 | 4.730 | 17.447  | 0.008 | 0.012 |
| 1425  | 0   | GET    | /user/icon  | 0.004 | 0.236 | 9.190   | 0.006 | 0.028 |
| 404   | 0   | POST   | /login      | 0.000 | 1.435 | 2.868   | 0.007 | 0.012 |
| 43    | 0   | POST   | /user       | 0.008 | 0.052 | 0.782   | 0.018 | 0.052 |
| 200   | 0   | GET    | /me         | 0.004 | 0.020 | 0.720   | 0.004 | 0.016 |
| 424   | 0   | POST   | /logout     | 0.000 | 0.008 | 0.493   | 0.001 | 0.008 |
| 1     | 0   | POST   | /initialize | 0.204 | 0.204 | 0.204   | 0.204 | 0.204 |
| 5     | 0   | PUT    | /me         | 0.008 | 0.020 | 0.060   | 0.012 | 0.020 |
| 3     | 0   | PUT    | /me/icon    | 0.028 | 0.032 | 0.060   | 0.020 | 0.032 |
+-------+-----+--------+-------------+-------+-------+---------+-------+-------+

→GET /calendarが遅くなるのでこちらを改善する

GET /calendarの改善:（313->657）

GET /calendarは会議参加者の存在有無を全アクセスに対して行っているが
無駄であるため、プログラム内のmapにキャッシュさせる。
この修正をいれるとアクセス数が増えnginxのファイルディスクリプタ数不足のエラー
が出たので以下の修正も入れた。
https://www.1x1.jp/blog/2013/02/nginx_too_many_open_files_error.html

isucon@ubuntu2004:~/r-isucon/bench$ ulimit -u 1024 && ./bin/bench -target http://localhost
17:04:56.450093 負荷レベルが上昇しました
17:05:16.263116 Language: go
17:05:16.263134 Reason: 負荷走行に成功しました
17:05:16.263139 Score: 657
17:05:16.263141 Load Level: 2
17:05:16.263142
17:05:16.263144 Critical Error count: 0
17:05:16.263145
17:05:16.263146 Application Error count: 0
17:05:16.263148
17:05:16.263149 Trivial Error count: 0
{
  "pass": true,
  "score": 657,
  "messages": [
    "Report ID: ccf4247a-ca2c-41cd-9f0e-230fa63ceaef",
    "負荷走行に成功しました",
    "Load Level: 2"
  ]
}
{
  "pass": true,
  "score": 657,
  "messages": [
    "Report ID: ccf4247a-ca2c-41cd-9f0e-230fa63ceaef",
    "負荷走行に成功しました",
    "Load Level: 2"
  ]
}

isucon@ubuntu2004:~/r-isucon/bench$ sudo alp ltsv --file=/var/log/nginx/access.log --config=./config.yml
+-------+-----+--------+-------------+-------+-------+--------+-------+-------+
| COUNT | 5XX | METHOD |     URI     |  MIN  |  MAX  |  SUM   |  AVG  |  P99  |
+-------+-----+--------+-------------+-------+-------+--------+-------+-------+
| 1313  | 0   | GET    | /calendar   | 0.004 | 4.704 | 88.386 | 0.067 | 0.164 |
| 1423  | 0   | GET    | /schedule   | 0.012 | 4.760 | 85.522 | 0.060 | 0.124 |
| 926   | 0   | PUT    | /schedule   | 0.020 | 4.756 | 81.939 | 0.088 | 0.432 |
| 433   | 0   | POST   | /schedule   | 0.008 | 4.736 | 42.884 | 0.099 | 1.724 |
| 2844  | 0   | GET    | /user/icon  | 0.004 | 4.700 | 34.385 | 0.012 | 0.056 |
| 5286  | 0   | GET    | /user       | 0.000 | 3.796 | 23.250 | 0.004 | 0.012 |
| 817   | 0   | POST   | /login      | 0.004 | 0.044 | 2.995  | 0.004 | 0.020 |
| 438   | 0   | GET    | /me         | 0.004 | 0.028 | 1.661  | 0.004 | 0.024 |
| 75    | 0   | POST   | /user       | 0.004 | 0.052 | 1.519  | 0.020 | 0.052 |
| 841   | 0   | POST   | /logout     | 0.000 | 0.016 | 1.042  | 0.001 | 0.008 |
| 16    | 0   | PUT    | /me/icon    | 0.020 | 0.072 | 0.472  | 0.030 | 0.072 |
| 1     | 0   | POST   | /initialize | 0.136 | 0.136 | 0.136  | 0.136 | 0.136 |
| 11    | 0   | PUT    | /me         | 0.001 | 0.016 | 0.113  | 0.010 | 0.016 |
| 5     | 0   | GET    | /api/me     | 0.000 | 0.004 | 0.008  | 0.002 | 0.004 |
+-------+-----+--------+-------------+-------+-------+--------+-------+-------+

→まだ/calendarが一番遅いが、同じくらい遅い/sheculeの改善に移ってみる

GET /scheduleの改善:（657 -> 925）

GET /scheduleの中でorecocoReserveへsheduleのmeeting roomの状況を
問い合わせているが、同じsheduleの状況についてはキャッシュできるため
r-calendar側にsheculeID毎のmeeting roomの状況をキャッシュさせる。

isucon@ubuntu2004:~/r-isucon/bench$ sudo alp ltsv --file=/var/log/nginx/access.log --config=./config.yml
+-------+-----+--------+-------------+-------+-------+--------+-------+-------+
| COUNT | 5XX | METHOD |     URI     |  MIN  |  MAX  |  SUM   |  AVG  |  P99  |
+-------+-----+--------+-------------+-------+-------+--------+-------+-------+
| 1944  | 0   | GET    | /schedule   | 0.016 | 1.416 | 90.447 | 0.047 | 0.252 |
| 1172  | 0   | PUT    | /schedule   | 0.024 | 2.572 | 80.152 | 0.068 | 0.284 |
| 1803  | 0   | GET    | /calendar   | 0.004 | 1.800 | 54.586 | 0.030 | 0.116 |
| 3905  | 0   | GET    | /user/icon  | 0.004 | 0.992 | 43.085 | 0.011 | 0.048 |
| 602   | 0   | POST   | /schedule   | 0.004 | 2.596 | 39.151 | 0.065 | 0.460 |
| 6802  | 0   | GET    | /user       | 0.004 | 0.816 | 27.386 | 0.004 | 0.012 |
| 1125  | 0   | POST   | /login      | 0.004 | 1.696 | 6.689  | 0.006 | 0.020 |
| 574   | 0   | GET    | /me         | 0.004 | 0.072 | 2.464  | 0.004 | 0.028 |
| 76    | 0   | POST   | /user       | 0.004 | 0.064 | 1.896  | 0.025 | 0.064 |
| 1145  | 0   | POST   | /logout     | 0.000 | 0.016 | 1.536  | 0.001 | 0.012 |
| 16    | 0   | PUT    | /me/icon    | 0.008 | 0.404 | 0.908  | 0.057 | 0.404 |
| 17    | 0   | PUT    | /me         | 0.008 | 0.036 | 0.248  | 0.015 | 0.036 |
| 1     | 0   | POST   | /initialize | 0.136 | 0.136 | 0.136  | 0.136 | 0.136 |
| 3     | 0   | GET    | /api/me     | 0.004 | 0.004 | 0.004  | 0.001 | 0.004 |
+-------+-----+--------+-------------+-------+-------+--------+-------+-------+

残課題

  • r-calendarにorecoco-reserveの機能を統合する
  • DBサーバとAPサーバを分離する

Discussion