isucon7に参加する準備


# 過去問（isucon6）の環境構築

ISUCONの過去問に挑戦するための環境構築をした
http://muttan1203.hatenablog.com/entry/isucon_practice_setup
→ メモリ４GのMacではフリーズしてしまった

このシェルコマンドをGCPインスタンス上で実行
https://github.com/matsuu/vagrant-isucon/blob/master/isucon6-qualifier/Vagrantfile#L79-L137

## GCP上のファイルをsshfsする
ここを参照にisuconユーザーでsshログインできるようにする。
（鍵の登録、isuconユーザーのauthorized_keys登録とか）
https://cloud.google.com/compute/docs/instances/connecting-to-instance#standardssh

sshログインできるようになったら、以下を参考にsshfsする
https://qiita.com/ysk24ok/items/bb148530a55a4e55d99b

# チューニング技術とか

ISUCON 夏期講習 2017 を開催しました（当日の資料あり）
http://isucon.net/archives/50648750.html

ISUCON6に参加して2年連続予選敗退してきました
https://www.muratayusuke.com/2016/09/22/isucon6/

# まずやること

## 確実にロールバックできるようにしておく

- アプリケーションのコードはgitで管理
- `/etc` 以下もgitで（rootユーザーでやる）
- DBのデータはバックアップ

## 言語の変更

自分たちが利用する言語にWebappを変更する

また、自動起動設定も忘れず変更

```
sudo systemctl disable isuda.perl
sudo systemctl disable isutar.perl
sudo systemctl enable isuda.js
sudo systemctl enable isutar.js
```

## 仕様の把握

ブラウザでアプリケーションにアクセスして、仕様を把握

動いているプロセスの確認

```sh
isucon@isucon:~/webapp/js$ pstree
systemd─┬─accounts-daemon─┬─{gdbus}
        │                 └─{gmain}
        ├─acpid
        ├─2*[agetty]
        ├─atd
        ├─cron
        ├─dbus-daemon
        ├─dhclient
        ├─google_accounts
        ├─google_clock_sk
        ├─google_ip_forwa
        ├─2*[iscsid]
        ├─isucon6q-bench-───7*[{isucon6q-bench-}]
        ├─isupam───4*[{isupam}]
        ├─lvmetad
        ├─lxcfs───2*[{lxcfs}]
        ├─mysqld───35*[{mysqld}]
        ├─nginx───2*[nginx]
        ├─2*[node─┬─3*[node─┬─4*[{V8 WorkerThread}]]]
        │         │         └─5*[{node}]]]
        │         ├─4*[{V8 WorkerThread}]]
        │         └─{node}]
        ├─ntpd───{ntpd}
        ├─polkitd─┬─{gdbus}
        │         └─{gmain}
        ├─rsyslogd─┬─{in:imklog}
        │          ├─{in:imuxsock}
        │          └─{rs:main Q:Reg}
        ├─snapd───6*[{snapd}]
        ├─sshd─┬─sshd───sshd───bash───sudo───sh
        │      ├─sshd───sshd───sh───bash───pstree
        │      └─sshd───sshd───sh───sftp-server
        ├─sshguard-journa─┬─journalctl
        │                 └─sshguard───{sshguard}
        ├─2*[systemd───(sd-pam)]
        ├─systemd-journal
        ├─systemd-logind
        ├─systemd-resolve
        ├─systemd-udevd
        └─uuidd

isucon@isucon:~/webapp/js$ ps auxwf
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root         2  0.0  0.0      0     0 ?        S    15:49   0:00 [kthreadd]
root         4  0.0  0.0      0     0 ?        S<   15:49   0:00  \_ [kworker/0:0H]
...
isucon   18689  0.0  0.0 472640  8020 ?        Ssl  16:49   0:05 /home/isucon/isucon6q/isucon6q-bench-worker
mysql    25489  0.2  2.9 1553432 244872 ?      Ssl  17:21   0:49 /usr/sbin/mysqld
root     25950  0.0  0.0 123336  1420 ?        Ss   17:21   0:00 nginx: master process /usr/sbin/nginx -g daemon on; master_process
www-data 25955  0.0  0.0 123756  4084 ?        S    17:21   0:01  \_ nginx: worker process
www-data 25956  0.0  0.0 123756  4084 ?        S    17:21   0:02  \_ nginx: worker process
isucon    3302  0.0  0.0  53644  6560 ?        Ssl  17:25   0:02 /home/isucon/bin/isupam -p 5050
shun91  4420  0.0  0.0  62760  5644 ?        Ss   22:48   0:00 /lib/systemd/systemd --user
shun91  4421  0.0  0.0  82780  2008 ?        S    22:48   0:00  \_ (sd-pam)
isucon    4532  0.0  0.7 926616 57860 ?        Ssl  22:50   0:02 /home/isucon/.local/node/bin/node /home/isucon/webapp/js/bin/run_is
isucon    4561  0.3  0.7 1226824 58168 ?       Sl   22:50   0:07  \_ /home/isucon/.local/node/bin/node /home/isucon/webapp/js/bin/ru
isucon    4567  0.3  0.9 1242896 75764 ?       Sl   22:50   0:07  \_ /home/isucon/.local/node/bin/node /home/isucon/webapp/js/bin/ru
isucon    4568  0.0  0.7 961392 58680 ?        Sl   22:50   0:01  \_ /home/isucon/.local/node/bin/node /home/isucon/webapp/js/bin/ru
isucon    4605  0.0  0.7 931796 62736 ?        Ssl  22:50   0:01 /home/isucon/.local/node/bin/node /home/isucon/webapp/js/bin/run_is
isucon    4633  0.0  0.6 1223120 53704 ?       Sl   22:50   0:01  \_ /home/isucon/.local/node/bin/node /home/isucon/webapp/js/bin/ru
isucon    4639  0.0  0.6 1223220 53176 ?       Sl   22:50   0:01  \_ /home/isucon/.local/node/bin/node /home/isucon/webapp/js/bin/ru
isucon    4640  0.0  0.6 1222344 54520 ?       Sl   22:50   0:01  \_ /home/isucon/.local/node/bin/node /home/isucon/webapp/js/bin/ru
isucon    4893  0.0  0.0  62760  5632 ?        Ss   23:09   0:00 /lib/systemd/systemd --user
isucon    4894  0.0  0.0  82780  2020 ?        S    23:09   0:00  \_ (sd-pam)
```

何のdeamonやミドルウェアで構成されているかを把握

## ベンチをかけながら様子を見る

各種モニタリングコマンドインストール

```
sudo apt-get -y install htop
sudo apt-get -y install dstat
sudo apt-get -y install glances
bash <(curl -Ss https://my-netdata.io/kickstart.sh) all
```

top
htop
dstat -t -a
glances

19999ポートにアクセスしてnetdataを見る

## 各種再起動を自動化するスクリプトを書く

表題の通り。一例は以下。

```sh:bin/restart.sh
#!/bin/sh
set -e

now=`date +%Y%m%d-%H%M%S`
mv /var/log/nginx/access.log /var/log/nginx/access.log.$now # nginxのログをローテート
systemctl reload nginx

mv /var/log/mysql/slow.log /var/log/mysql/slow.log.$now # mysqlのslowlogをローテート
mysqladmin -uisucon -pisucon flush-logs

# アプリケーションの再起動
systemctl restart isuda.js
systemctl restart isutar.js

# エラーが出てないかログを見る
journalctl -f
```

最後は `ctrl + C` で終了する。

## アクセスログの解析

alpのインストール

```
wget https://github.com/tkuchiki/alp/releases/download/v0.3.1/alp_linux_amd64.zip
unzip alp_linux_amd64.zip
sudo install ./alp /usr/local/bin

sudo vi /etc/nginx/nginx.conf

----
# http { ... server { に追記
http {
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"
                "\tcache:$upstream_http_x_cache"
                "\truntime:$upstream_http_x_runtime"
                "\tapptime:$upstream_response_time"
                "\tvhost:$host";
access_log /var/log/nginx/access.log ltsv;
    server {
----

sudo rm /var/log/nginx/access.log && sudo systemctl reload nginx
```

ベンチを回した後に、以下のコマンドで解析。
見方は以下を参照。
http://papix.hatenablog.com/entry/2015/09/28/094310

```
alp --sum -r -f /var/log/nginx/access.log --aggregates='/keyword/.*'
+-------+-------+--------+---------+--------+-------+--------+--------+--------+------------+------------+-------------+------------+--------+-----------------------------------+
| COUNT |  MIN  |  MAX   |   SUM   |  AVG   |  P1   |  P50   |  P99   | STDDEV | MIN(BODY)  | MAX(BODY)  |  SUM(BODY)  | AVG(BODY)  | METHOD |                URI                |
+-------+-------+--------+---------+--------+-------+--------+--------+--------+------------+------------+-------------+------------+--------+-----------------------------------+
|    29 | 2.780 | 15.001 | 369.046 | 12.726 | 2.780 | 14.999 | 15.001 |  3.895 |      0.000 |  39905.000 |  302519.000 |  10431.690 | GET    | /                                 |
|    30 | 0.643 |  9.752 | 132.769 |  4.426 | 0.643 |  4.573 |  9.165 |  2.962 |      0.000 |  44219.000 |  240517.000 |   8017.233 | GET    | /keyword/.*                       |
|    52 | 0.008 |  2.999 |  69.714 |  1.341 | 0.008 |  1.669 |  2.999 |  1.053 |      0.000 |     33.000 |    1416.000 |     27.231 | POST   | /login                            |
|    30 | 0.077 |  3.001 |  67.497 |  2.250 | 0.077 |  2.634 |  3.001 |  1.004 |      5.000 |     33.000 |     271.000 |      9.033 | POST   | /keyword                          |
|    57 | 0.006 |  1.873 |  28.094 |  0.493 | 0.006 |  0.137 |  1.845 |  0.602 | 106015.000 | 106015.000 | 6042855.000 | 106015.000 | GET    | /css/bootstrap.min.css            |
|    29 | 0.005 |  1.873 |  14.798 |  0.510 | 0.005 |  0.078 |  1.846 |  0.660 |  28631.000 |  28631.000 |  830299.000 |  28631.000 | GET    | /js/bootstrap.min.js              |
|    29 | 0.002 |  1.316 |  13.675 |  0.472 | 0.002 |  0.341 |  1.132 |  0.435 |   1092.000 |   1092.000 |   31668.000 |   1092.000 | GET    | /favicon.ico                      |
|    29 | 0.004 |  1.407 |  13.197 |  0.455 | 0.004 |  0.273 |  1.359 |  0.463 |     93.000 |     93.000 |    2697.000 |     93.000 | GET    | /img/star.gif                     |
|    29 | 0.003 |  1.654 |  12.717 |  0.439 | 0.003 |  0.105 |  1.445 |  0.527 |  86351.000 |  86351.000 | 2504179.000 |  86351.000 | GET    | /js/jquery.min.js                 |
|    29 | 0.005 |  1.365 |  11.412 |  0.394 | 0.005 |  0.091 |  1.288 |  0.454 |  16849.000 |  16849.000 |  488621.000 |  16849.000 | GET    | /css/bootstrap-responsive.min.css |
|    70 | 0.001 |  0.778 |   6.722 |  0.096 | 0.001 |  0.003 |  0.748 |  0.192 |      9.000 |      9.000 |     630.000 |      9.000 | POST   | /top4aew4fe9yeehu/job/new         |
|    11 | 0.019 |  1.419 |   6.499 |  0.591 | 0.019 |  0.329 |  1.227 |  0.415 |      9.000 |     20.000 |     209.000 |     19.000 | POST   | /stars                            |
|     1 | 0.038 |  0.038 |   0.038 |  0.038 | 0.038 |  0.038 |  0.038 |  0.000 |     20.000 |     20.000 |      20.000 |     20.000 | GET    | /initialize                       |
|     1 | 0.006 |  0.006 |   0.006 |  0.006 | 0.006 |  0.006 |  0.006 |  0.000 |     79.000 |     79.000 |      79.000 |     79.000 | GET    | /css/main.css                     |
|     1 | 0.005 |  0.005 |   0.005 |  0.005 | 0.005 |  0.005 |  0.005 |  0.000 |    695.000 |    695.000 |     695.000 |    695.000 | GET    | /js/star.js                       |
|     1 | 0.003 |  0.003 |   0.003 |  0.003 | 0.003 |  0.003 |  0.003 |  0.000 |     33.000 |     33.000 |      33.000 |     33.000 | GET    | /logout                           |
+-------+-------+--------+---------+--------+-------+--------+--------+--------+------------+------------+-------------+------------+--------+-----------------------------------+
```
SUMやAVGが高い部分にボトルネックがあると考えたらよさそう？

## MySQLのクエリログの解析

まず、全てのクエリログが吐かれるように `/etc/mysql/my.cnf` の `[mysqld]` のセクションに追記する。

```
[mysqld]
slow_query_log = 1
slow_query_log_file = /var/log/mysql/slow.log
long_query_time = 0
```

追記したらmysqlやアプリケーションを再起動。

```
sudo systemctl restart mysql
sudo systemctl restart isuda.js
sudo systemctl restart isutar.js
```

クエリログ解析用のツールをインストール

```
sudo apt-get install percona-toolkit
```

下記コマンドで解析できる。
実行時間が長い順？に表示されているので、ひと目で時間がかかっているクエリが分かる

```
sudo pt-query-digest --limit 10 /var/log/mysql/slow.log

...
# Profile
# Rank Query ID           Response time Calls R/Call V/M   Item
# ==== ================== ============= ===== ====== ===== ============
#    1 0x6C987DBB94BEC091 12.9477 96.1%    80 0.1618  0.00 SELECT entry
#    2 0x0C85264D3C24C18B  0.4724  3.5%     8 0.0591  0.34 SELECT entry
#    3 0x06A9A84CCACAFA63  0.0265  0.2%     8 0.0033  0.01 SELECT entry
#    4 0x782FEBA311BC59ED  0.0182  0.1%    80 0.0002  0.00 SELECT star
#    5 0x5E7B7A2B492F56AC  0.0068  0.1%    88 0.0001  0.00 SET
#    6 0x04FE01C5B31FD305  0.0041  0.0%   232 0.0000  0.00 ADMIN PING
#    7 0x746D96521AE5B82C  0.0036  0.0%    88 0.0000  0.00 SET
#    8 0xAA353644DE4C4CB4  0.0003  0.0%    76 0.0000  0.00 ADMIN QUIT

# Query 1: 0 QPS, 0x concurrency, ID 0x6C987DBB94BEC091 at byte 1192 _____
# Scores: V/M = 0.00
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         12      80
# Exec time     96     13s   132ms   235ms   162ms   208ms    21ms   155ms
# Lock time     31     7ms    57us   196us    84us   113us    25us    73us
# Rows sent     99 555.31k   6.94k   6.94k   6.94k   6.94k       0   6.94k
# Rows examine  90   1.08M  13.88k  13.88k  13.88k  13.88k       0  13.88k
# Query size    17   4.61k      59      59      59      59       0      59
# String:
# Databases    isuda
# Hosts        localhost
# Time         2017-10-16... (1/1%), 2017-10-16... (1/1%)... 78 more
# Users        isucon
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms  ################################################################
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isuda` LIKE 'entry'\G
#    SHOW CREATE TABLE `isuda`.`entry`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM entry ORDER BY CHARACTER_LENGTH(keyword) DESC\G
...
```

# チューニングポイント

- 静的ファイルはnginxで配布
- 遅いクエリの改善
	- `select *` は遅い
	- indexを適切に張る
	- offsetの破棄（まずidだけでソート→対象idを取り出し、もっかいクエリ投げる）
- キャッシュする（redisとか）
	- DBをキャッシュする
	- HTMLをキャッシュする
	- テンプレートエンジンをキャッシュする
- マイクロサービスをやめる
- 正規表現の最適化
- （ベンチマーカーの挙動を解析する。アクセスログとか見て。）

# その他

## アプリケーションログの場所

```
sudo tail -f /var/log/syslog
```

## redisのインストール

```
sudo apt-get install redis-server
```

参考
http://programmer-jobs.blogspot.jp/2017/02/redis-in-memory-data-store-ubuntu.html

## MySQLのインストールと自動起動設定など

これのまま
http://ksino.hatenablog.com/entry/2016/11/17/232619

自動起動

```
sudo apt-get install language-pack-ja-base
sudo systemctl enable mysql
```

## MySQLのダンプとそこからの復元

dump

```
mysqldump -u[username] -p[password] [schema] [table] > ***.dump
```

復元

```
# databaseが作成されてない場合は作成しておく
> create database [schema];

# dumpから復元
$ sudo mysql -u[username] -p[password] < ***.dump
```

## nginxのインストールと自動起動設定など

```
wget -qO - https://nginx.org/keys/nginx_signing.key | sudo apt-key add -
sudo vim /etc/apt/sources.list.d/nginx.list

---- 以下の内容を記述
deb http://nginx.org/packages/ubuntu/ xenial nginx
deb-src http://nginx.org/packages/ubuntu/ xenial nginx
----

sudo apt-get update
sudo apt-get install nginx

sudo apt-get install language-pack-ja-base
sudo systemctl enable nginx
```

## nodeからredisを触る

```
npm i redis -S
```

https://www.npmjs.com/package/redis