Open5
目指せISUCONマスター
Taka環境構築
EC2
AMIから起動
| 用途 | AMI | インスタンスタイプ |
|---|---|---|
| 競技者 | ami-0bed62bba4100a4b7 | c7g.large |
| ベンチ | ami-034a457f6af55d65d | c7g.xlarge |
競技者用で80ポートの後悔を忘れずに
ベンチ動作確認
$ sudo su - isucon
$ private_isu.git/benchmarker/bin/benchmarker -u private_isu.git/benchmarker/userdata -t http://<kyougisha_ip>
初期値
{"pass":true,"score":318,"success":366,"fail":6,"messages":["リクエストがタイムアウトしました (POST /login)","リクエストがタイムアウトしました (POST /register)"]}
改善開始
indexをはる
topでMySQLのCPU使用率が90%+であることがわかったので、indexを貼ってボトルネックを解消する
slow queryを吐きだす
$ cd /etc/mysql.conf.d/mysqld.cnf
slow_query_log = 1
slow_query_log_file = /var/log/mysql/mysql-slow.log
long_query_time = 0
再起動
sudo systemctl restart mysql
スロークエリが作成されているかの確認
一回ベンチを走らせる
ubuntu@ip-172-31-11-221:/var/log/mysql$ ls
error.log mysql-slow.log
スロークエリ出力
sudo mysqldumpslow mysql-slow.log -s t
Reading mysql slow query log from mysql-slow.log
Count: 1061 Time=0.05s (55s) Lock=0.00s (0s) Rows=2.7 (2901), isuconp[isuconp]@localhost
SELECT * FROM `comments` WHERE `post_id` = N ORDER BY `created_at` DESC LIMIT N
MySQLにアクセス
passwordはここから
cat /etc/mysql/debian.cnf
index作成
mysql> create index post_id_idx on comments(post_id);
Query OK, 0 rows affected (0.91 sec)
Records: 0 Duplicates: 0 Warnings: 0
mysql> show index from comments;
+----------+------------+-------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+---------+------------+
| Table | Non_unique | Key_name | Seq_in_index | Column_name | Collation | Cardinality | Sub_part | Packed | Null | Index_type | Comment | Index_comment | Visible | Expression |
+----------+------------+-------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+---------+------------+
| comments | 0 | PRIMARY | 1 | id | A | 100169 | NULL | NULL | | BTREE | | | YES | NULL |
| comments | 1 | post_id_idx | 1 | post_id | A | 9613 | NULL | NULL | | BTREE | | | YES | NULL |
+----------+------------+-------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+---------+------------+
2 rows in set (0.01 sec)
CPUの負荷が分散されていい感じ
1048 isucon 20 0 607296 60928 9600 S 28.6 1.6 0:14.72 ruby
2788 mysql 20 0 1824428 476280 35456 S 24.3 12.2 1:26.63 mysqld
点数向上
{"pass":true,"score":5049,"success":4350,"fail":0,"messages":[]}
言語変更
goにする
manual.md
$ ubuntu@ip-172-31-11-221:/var/log/mysql$ sudo systemctl stop isu-ruby
$ ubuntu@ip-172-31-11-221:/var/log/mysql$ sudo systemctl disable isu-ruby
Removed "/etc/systemd/system/multi-user.target.wants/isu-ruby.service".
$ ubuntu@ip-172-31-11-221:/var/log/mysql$ sudo systemctl start isu-go
$ ubuntu@ip-172-31-11-221:/var/log/mysql$ sudo systemctl enable isu-go
Created symlink /etc/systemd/system/multi-user.target.wants/isu-go.service → /etc/systemd/system/isu-go.service.
めっちゃ向上
isucon@ip-172-31-0-251:~$ private_isu.git/benchmarker/bin/benchmarker -u private_isu.git/benchmarker/userdata -t http://18.183.53.176
{"pass":true,"score":24029,"success":22669,"fail":0,"messages":[]}
idelが0.5%になった
$ top
%Cpu(s): 63.1 us, 28.4 sy, 0.0 ni, 0.5 id, 0.5 wa, 0.0 hi, 7.5 si, 0.0 st
MiB Mem : 3808.1 total, 1224.3 free, 1175.1 used, 1573.7 buff/cache
MiB Swap: 0.0 total, 0.0 free, 0.0 used. 2633.0 avail Mem
alpでアクセスログの解析
install
armの場合
$ wget https://github.com/tkuchiki/alp/releases/download/v1.0.21/alp_linux_arm64.zip
$ ubuntu@ip-172-31-11-221:~$ unzip alp_linux_arm64.zip
Archive: alp_linux_arm64.zip
inflating: alp
$ ubuntu@ip-172-31-11-221:~$ sudo install alp /usr/local/bin/alp
Command 'udo' not found, but can be installed with:
sudo apt install udo
ubuntu@ip-172-31-11-221:~$ sudo install alp /usr/local/bin/alp
ubuntu@ip-172-31-11-221:~$ alp --version
1.0.21
nginxの設定
logの形式をjsonにしないとalpが使いえないので
$ ubuntu@ip-172-31-11-221:/etc/nginx$ cat nginx.conf
##
# Logging Settings
##
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;
文法チェック
root@ip-172-31-11-221:/etc/nginx# nginx -t
nginx: the configuration file /etc/nginx/nginx.conf syntax is ok
nginx: configuration file /etc/nginx/nginx.conf test is successful
再起動
root@ip-172-31-11-221:/etc/nginx# systemctl reload nginx
うまくいかないのでLTSVに変更
log_format ltsv "time:$time_local"
"\thost:$remote_addr"
"\tforwardedfor:$http_x_forwarded_for"
"\treq:$request"
"\tstatus:$status"
"\tmethod:$request_method"
"\turi:$request_uri"
"\tsize:$body_bytes_sent"
"\treferer:$http_referer"
"\tua:$http_user_agent"
"\treqtime:$request_time"
"\truntime:$upstream_http_x_runtime"
"\tapptime:$upstream_response_time"
"\tvhost:$host";
access_log /var/log/nginx/access.log ltsv;
nginxを再起動してログをクリア
sudo nginx -t
sudo systemctl restart nginx
sudo sh -c 'echo "" > /var/log/nginx/access.log'
出力
alp ltsv --file=/var/log/nginx/access.log
静的ファイルをnginxで配信する
alp command
パターンごとに出力をまとめる
@ root@ip-172-31-15-67:/home/isucon# alp ltsv --file=/var/log/nginx/access.log -m "/posts/[0-9]+,/image/[0-9]+,/comment/[0-9]+" -o count,method,uri,min,avg,max,sum
access.logのクリア
root@ip-172-31-15-67:~# truncate -s 0 /var/log/nginx/access.log
root@ip-172-31-15-67:~# ls -l /var/log/nginx/access.log
-rw-r----- 1 www-data adm 0 Nov 9 16:58 /var/log/nginx/access.log
configの修正
$ root@ip-172-31-15-67:/etc/nginx/sites-enabled# vim isucon.conf
server {
listen 80;
client_max_body_size 10m;
root /home/isucon/private_isu/webapp/public/;
location ~ ^/(favicon\.ico|css/|js/|img/) {
expires 1d;
}
location / {
proxy_set_header Host $host;
proxy_pass http://localhost:8080;
}
}
Before:
Score:
v1:
{"pass":true,"score":25985,"success":24509,"fail":0,"messages":[]}
v2:
{"pass":true,"score":25269,"success":23823,"fail":0,"messages":[]}
log
v1:
+-------+--------+--------------------+-------+-------+-------+---------+
| COUNT | METHOD | URI | MIN | AVG | MAX | SUM |
+-------+--------+--------------------+-------+-------+-------+---------+
| 1548 | GET | /favicon.ico | 0.000 | 0.002 | 0.030 | 3.700 |
| 1548 | GET | /js/timeago.min.js | 0.000 | 0.002 | 0.033 | 3.741 |
| 1548 | GET | /js/main.js | 0.000 | 0.002 | 0.041 | 3.690 |
| 1548 | GET | /css/style.css | 0.000 | 0.002 | 0.039 | 3.692 |
| 14531 | GET | /image/[0-9]+ | 0.001 | 0.009 | 0.092 | 129.840 |
+-------+--------+--------------------+-------+-------+-------+---------+
v2:
+-------+--------+--------------------+-------+-------+-------+---------+
| COUNT | METHOD | URI | MIN | AVG | MAX | SUM |
+-------+--------+--------------------+-------+-------+-------+---------+
| 1512 | GET | /favicon.ico | 0.000 | 0.003 | 0.087 | 3.964 |
| 1512 | GET | /js/main.js | 0.001 | 0.002 | 0.036 | 3.696 |
| 1512 | GET | /css/style.css | 0.001 | 0.003 | 0.035 | 3.913 |
| 1512 | GET | /js/timeago.min.js | 0.001 | 0.002 | 0.029 | 3.773 |
| 14068 | GET | /image/[0-9]+ | 0.000 | 0.009 | 0.093 | 132.723 |
+-------+--------+--------------------+-------+-------+-------+---------+
After:
Score
v1:
{"pass":true,"score":26468,"success":25017,"fail":0,"messages":[]}
v2:
{"pass":true,"score":26366,"success":24925,"fail":0,"messages":[]}
log
v1:
+-------+--------+--------------------+-------+-------+-------+---------+
| COUNT | METHOD | URI | MIN | AVG | MAX | SUM |
+-------+--------+--------------------+-------+-------+-------+---------+
| 1645 | GET | /favicon.ico | 0.000 | 0.000 | 0.000 | 0.000 |
| 1645 | GET | /js/main.js | 0.000 | 0.000 | 0.000 | 0.000 |
| 1645 | GET | /css/style.css | 0.000 | 0.000 | 0.000 | 0.000 |
| 1645 | GET | /js/timeago.min.js | 0.000 | 0.000 | 0.000 | 0.000 |
| 14592 | GET | /image/[0-9]+ | 0.001 | 0.009 | 0.084 | 135.045 |
+-------+--------+--------------------+-------+-------+-------+---------+
v2:
+-------+--------+--------------------+-------+-------+-------+---------+
| COUNT | METHOD | URI | MIN | AVG | MAX | SUM |
+-------+--------+--------------------+-------+-------+-------+---------+
| 1632 | GET | /css/style.css | 0.000 | 0.000 | 0.000 | 0.000 |
| 1632 | GET | /favicon.ico | 0.000 | 0.000 | 0.000 | 0.000 |
| 1632 | GET | /js/timeago.min.js | 0.000 | 0.000 | 0.000 | 0.000 |
| 1632 | GET | /js/main.js | 0.000 | 0.000 | 0.000 | 0.000 |
| 14573 | GET | /image/[0-9]+ | 0.001 | 0.009 | 0.086 | 134.563 |
+-------+--------+--------------------+-------+-------+-------+---------+
結論
レスポンスタイムを考えて、Nginxから配信されていることがわかる