はじめに

これを利用して、ISUCON の練習をします。

以下でベンチマーカーを動かすところまでできます。

$ git clone https://github.com/matsuu/vagrant-isucon.git
$ cd isucon9-qualifier-standalone
$ vagrant up
$ vagrant ssh
# VM上で以下
$ sudo -i -u isucon
$ cd isucari
$ bin/benchmarker

Nginx のアクセスログが吐かれない問題

kataribe を利用してアクセスログの解析を行おうとしました。

github.com

Nginx の設定ファイルを適用して、ベンチマークを回しても/var/log/nginx/access.logが空でした。設定ファイルのログのパスやシンタックスエラーの影響でうまく動いていないなど可能性を考えましたが、アクセスログが記録されることはありませんでした。

そもそもベンチマーカーのリクエストが Nginx を通っていないのではないのかと考えました。

$ ./bin/benchmarker -help
Usage of isucon9q:
  -allowed-ips string
        allowed ips (comma separated)
  -data-dir string
        data directory (default "initial-data")
  -payment-port int
        payment service port (default 5555)
  -payment-url string
        payment url (default "http://localhost:5555")
  -shipment-port int
        shipment service port (default 7000)
  -shipment-url string
        shipment url (default "http://localhost:7000")
  -static-dir string
        static file directory (default "webapp/public/static")
  -target-host string
        target host (default "isucon9.catatsuy.org")
  -target-url string
        target url (default "http://127.0.0.1:8000")

ベンチマーカーのオプションに-target-urlがあり、default では"http://127.0.0.1:8000"です。これは調べてみると、Go のアプリケーションサーバーの URL でした。 Nginx を通っていなかったということになります。

Nginx の設定ファイルを Go へプロキシするように変更します。ついでに、kataribe 用にログフォーマットも指定します。

http {
    <!-- kataribe用にログフォーマットを設定 -->
    log_format with_time '$remote_addr - $remote_user [$time_local] '
                        '"$request" $status $body_bytes_sent '
                        '"$http_referer" "$http_user_agent" $request_time';
    access_log /var/log/nginx/access.log with_time;

    <!-- 略 -->

    <!-- Goへプロキシ、Nginxは:8080でリクエストを受ける -->
    server {
        listen 8080;
        location / {
            proxy_pass http://localhost:8000;
        }
    }
}

ベンチマーカー起動時に Nginx の URL を設定してあげます。アクセスログが記録されており、kataribe による分析も行われました。

$ bin/benchmarker -target-url http://127.0.0.1:8080
$ sudo cat /var/log/nginx/access/log | kataribe -f ./kataribe.toml
Top 20 Sort By Count
Count    Total    Mean  Stddev    Min  P50.0  P90.0  P95.0  P99.0    Max   2xx  3xx  4xx  5xx  TotalBytes   MinBytes  MeanBytes   MaxBytes  Request
 1566   18.105  0.0116  0.0322  0.001  0.007  0.021  0.030  0.076  0.943  1566    0    0    0     3480049       1855       2222       4073  items/.json
  460  233.900  0.5085  0.4089  0.004  0.393  0.971  1.280  2.167  3.644   458    0    2    0    10769497          0      23411      24058  new_items/.json
  231   87.055  0.3769  0.2804  0.045  0.286  0.682  0.998  1.320  2.295   231    0    0    0     3061357         97      13252      24033  users/num.json
<!-- 略 -->

MySQL リスタートできない問題

最初は、ベンチマーカーによりスコアが計測でき MySQL も正常に動いていました。しかし、 MySQL 秘伝のタレを設定しリスタートすると問題は起きました。

isucon@ip-*-*-*-*:~$ sudo systemctl restart mysql
Job for mysql.service failed because the control process exited with error code.
See "systemctl status mysql.service" and "journalctl -xe" for details.

エラーログを見にいくと、以下のエラーが出ていました。

 [ERROR] InnoDB: Error number 28 means 'No space left on device'

この問題の原因は、EC2 の初期設定のディスク容量が少なかったことでした。出場する三人で共同に作業するために、EC2 上に Vagrant で環境構築をしていました。

Makefile の準備

初期セットアップコマンドや、EC2 にコードの変更を反映させるコマンド、計測して結果を Slack に通知するコマンドは事前に用意します。 ISUCON 参加記事を読んで良さげな Makefile を参考にさせてもらうことにします。

github.com

NGX_LOG:=/var/log/nginx/access.log
MYSQL_LOG:=/tmp/slow-query.log
SLACKCAT:=slackcat --tee

# これはベンチマーカーを動かす前にするタスクです
# - git pullで最新の状態にする
# - 新しいログを記録するために古いログを移動する
# - MySQLとNginxの設定ファイルを更新する
# - MySQLとNginxをリスタートする
.PHONY: before
before:
    git pull
    $(eval when := $(shell date "+%s"))
    mkdir -p ~/logs/$(when)
    @if [ -f $(NGX_LOG) ]; then \
        sudo mv -f $(NGX_LOG) ~/logs/$(when)/ ; \
    fi
    @if [ -f $(MYSQL_LOG) ]; then \
        sudo mv -f $(MYSQL_LOG) ~/logs/$(when)/ ; \
    fi
    sudo cp nginx.conf /etc/nginx/nginx.conf
    sudo cp my.cnf /etc/mysql/my.cnf
    sudo systemctl restart nginx
    sudo systemctl restart mysql

# これはスロークエリログを分析して、Slack で結果を通知するタスクです
.PHONY: slow
slow:
    sudo pt-query-digest $(MYSQL_LOG) | $(SLACKCAT)

# これはNginxのアクセスログを分析して、Slack で結果を通知するタスクです
.PHONY: kataru
kataru:
    sudo cat $(NGX_LOG) | kataribe -f ./kataribe.toml | $(SLACKCAT)

# これは計測用のツールを入れたりする一番最初にするタスクです
.PHONY: setup
setup:
    sudo apt install -y percona-toolkit dstat git unzip snapd
    sudo git config --global user.email "hoge@hoge.com"
    sudo git config --global user.name "hoge"
    wget https://github.com/matsuu/kataribe/releases/download/v0.4.1/kataribe-v0.4.1_linux_amd64.zip -O kataribe.zip
    unzip -o kataribe.zip
    sudo mv kataribe /usr/local/bin/
    sudo chmod +x /usr/local/bin/kataribe
    rm kataribe.zip
    kataribe -generate
    wget https://github.com/KLab/myprofiler/releases/download/0.2/myprofiler.linux_amd64.tar.gz
    tar xf myprofiler.linux_amd64.tar.gz
    rm myprofiler.linux_amd64.tar.gz
    sudo mv myprofiler /usr/local/bin/
    sudo chmod +x /usr/local/bin/myprofiler
    wget https://github.com/bcicen/slackcat/releases/download/v1.5/slackcat-1.5-linux-amd64 -O slackcat
    sudo mv slackcat /usr/local/bin/
    sudo chmod +x /usr/local/bin/slackcat
    slackcat --configure

おわりに

ISUCON で計測までたどり着くのにかなり時間がかかりました。おそらく、初めて ISUCON に挑戦する人は計測するまでにたくさんハマると思います。それのために、少しでも助けになればと思い記事にまとめました。ここまですれば計測が始められる思います。

🤖

:gijutsu_burogu:

VagrantでISUCONを練習しようとしてハマったことと計測の準備

はじめに

Nginx のアクセスログが吐かれない問題

MySQL リスタートできない問題

Makefile の準備

おわりに