Gマイナー志向

とくに意味はありません

ISUCON10予選で12位になり本選進出を決めました

TL;DR

ISUCON10の本選出場が決定しました。わいわい。 予選12位、最終スコアは2837でした。

毎年素晴らしいコンテストを開催してくださる運営様には、本当に頭が下がります。いつもありがとうございます。 本選もがんばるぞ!

体制

チーム名 ウー馬場ーイーツ

あいこん なまえ やくわり
f:id:tmatsuu:20190909215748j:plain:w100 matsuu バリバリ実装する前衛
f:id:tmatsuu:20190909215614p:plain:w100 netmarkjp 司令塔
f:id:tmatsuu:20190909215620j:plain:w100 ishikawa84g SELinuxAppArmorとレギュレーションやコードやDiscordを見るセキュリティ&情報官

今回は3人が同じ場所に集まらずすべてリモート体制としました。 3人だけのDiscordサーバを用意し、Discord上で画面共有と音声チャットで進めています。

方針

毎年同じですが

  • sshで接続してtmux上でvimで直接編集
  • isuumo配下でgit initを実行するが履歴保存用でbranchは作成しない

毎年今年こそはvscodeとか夢見るんですが、結局手に馴染んだtmux+vimが最強というオチです。

解析ツール

使用した解析ツールは以下の通り。

  • dstat
  • kataribe
  • mysqltuner.pl
  • pt-query-digest
  • top

ベンチマーク実行中はdstatとtopで負荷状況を目視確認しています。 ベンチマーク実行後はkataribeとpt-query-digestでログ解析、おまけでmysqltuner.plを実行しています。

事前にNew Relicも確認してましたが、goでは導入に骨が折れるので利用しませんでした。

最終構成

最終構成は以下の通りです。

サーバ 構成要素 備考
1台目 nginx+go バージョン変更なし
2台目 mysql 8.0.21にアップグレード
3台目 使用せず(!!!)

3台目も活用できればもっといけたかもですね。

ベンチマーク結果

f:id:tmatsuu:20200913131101p:plain

初動

pt-query-digestとkataribeで集計できるようmysqlとnginxの設定変更。

/etc/mysql/mysql.conf.d/mysqld.cnf

+
+slow_query_log=1
+slow_query_log_file=/var/log/mysql/mysql-slow.log
+long_query_time=0

/etc/nginx/nginx.conf

     log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '
                       '$status $body_bytes_sent "$http_referer" '
-                      '"$http_user_agent" "$http_x_forwarded_for"';
+                      '"$http_user_agent" $request_length $request_time';

$request_length も追加するのが最近のお気に入りです。

マニュアルを読む

マニュアルを読んだ段階でnginxでUser-Agentによるbotフィルタ実施。正規表現を読み砕いて不要な表現は削除しています。

/etc/nginx/sites-available/issumo.conf

+map $http_user_agent $bot {
+  default 0;
+  "~ISUCONbot" 1;
+  "~Mediapartners-ISUCON" 1;
+  "~ISUCONCoffee" 1;
+  "~ISUCONFeedSeeker" 1;
+  "~crawler \(https://isucon\.invalid/(support/faq/|help/jp/)" 1;
+  "~isubot" 1;
+  "~Isupider" 1;
+  "~*(bot|crawler|spider)(?:[-_ .\/;@()]|$)" 1;
+}
+
 server {
     root /home/isucon/isucon10-qualify/webapp/public;
     listen 80 default_server;
     listen [::]:80 default_server;

+    if ($bot = 1) {
+        return 503;
+    }
+

curlで該当するUser-Agentでアクセスしてみて503応答になることを確認。

初回ベンチ実行

topとdstatを実行しながらベンチマーク実施。この時点でmysqldのCPU負荷が支配的であることを確認。 pt-query-digestの結果をもとにインデックスを追加しました。

isuumo/webapp/mysql/db/3_index.sql

-- この時点で追加したインデックスは記録が取れておらず記憶があいまい
ALTER TABLE isuumo.estate ADD INDEX (rent, popularity);
ALTER TABLE isuumo.estate ADD INDEX (door_width, door_height, popularity);
ALTER TABLE isuumo.estate ADD INDEX (popularity);
ALTER TABLE isuumo.chair ADD INDEX (stock, price);
ALTER TABLE isuumo.chair ADD INDEX (price);

ADMIN PREPARE対策

ADMIN PREPAREが多い。DBへの接続時に自動prepareをしないようDSNに interpolateParams=true を追加しました。

 func (mc *MySQLConnectionEnv) ConnectDB() (*sqlx.DB, error) {
-       dsn := fmt.Sprintf("%v:%v@tcp(%v:%v)/%v", mc.User, mc.Password, mc.Host, mc.Port, mc.DBName)
+       dsn := fmt.Sprintf("%v:%v@tcp(%v:%v)/%v?interpolateParams=true", mc.User, mc.Password, mc.Host, mc.Port, mc.DBName)
        return sqlx.Open("mysql", dsn)
 }

なぞって検索対策

なぞって検索に関連するSQLの実行回数が異常に多いことからN+1実装となっていることを確認。1発のクエリーで取得できるよう変更しました。

SELECT * FROM estate WHERE latitude <= ? AND latitude >= ? AND longitude <= ? AND longitude >= ? AND ST_Contains(ST_PolygonFromText(?), POINT(latitude, longitude)) ORDER BY popularity DESC, id ASC LIMIT ?

rentなどの範囲による絞り込みをID化

pt-query-digestの上位クエリーがrentなどの範囲(range)による絞り込みになっておりインデックスを効かせにくいと判断してrentのIDを格納するカラムをテーブルに追加しています。

ALTER TABLE isuumo.estate ADD COLUMN rent_id INTEGER NOT NULL DEFAULT 0;
ALTER TABLE isuumo.estate ADD COLUMN door_height_id INTEGER NOT NULL DEFAULT 0;
ALTER TABLE isuumo.estate ADD COLUMN door_width_id INTEGER NOT NULL DEFAULT 0;

ALTER TABLE isuumo.chair ADD COLUMN height_id INTEGER NOT NULL DEFAULT 0;
ALTER TABLE isuumo.chair ADD COLUMN width_id INTEGER NOT NULL DEFAULT 0;
ALTER TABLE isuumo.chair ADD COLUMN depth_id INTEGER NOT NULL DEFAULT 0;
ALTER TABLE isuumo.chair ADD COLUMN price_id INTEGER NOT NULL DEFAULT 0;

UPDATE estate SET rent_id = 0 WHERE rent < 50000;
UPDATE estate SET rent_id = 1 WHEN 50000 <= rent AND rent < 100000;
UPDATE estate SET rent_id = 2 WHEN 100000 <= rent AND rent < 150000;
UPDATE estate SET rent_id = 3 WHEN 150000 <= rent;
ALTER TABLE estate ADD INDEX (rent_id);
-- 以下同様のため省略

条件のSQL生成がすっきり。

-               if estateRent.Min != -1 {
-                       conditions = append(conditions, "rent >= ?")
-                       params = append(params, estateRent.Min)
-               }
-               if estateRent.Max != -1 {
-                       conditions = append(conditions, "rent < ?")
-                       params = append(params, estateRent.Max)
-               }
+               conditions = append(conditions, "rent_id = ?")
+               params = append(params, estateRent.ID)
        }

INSERT前に rent_id に格納する値を計算。

var rentId int64
switch {
        case rent < 50000:
                rentId = 0
        case rent < 100000:
                rentId = 1
        case rent < 150000:
                rentId = 2
        default:
                rentId = 3
}

SELECT * FROM ...rent_id などを取り除いたカラムを列挙。

-- 変更前
SELECT * FROM estate ...
SELECT * FROM chair ...
-- 変更後
SELECT id, name, description, thumbnail, address, latitude, longitude, rent, door_height, door_width, features, popularity FROM estate ...
SELECT id, name, description, thumbnail, price, height, width, depth, color, features, kind, popularity, stock FROM chair ...

initializeがタイムアウト

上記設定後に実行したベンチマーク結果のpt-query-digestの上位クエリーにさらにインデックスを追加していくと、initializeが30秒以内に終わらなくなる。

今回各テーブルの descriptionVARCHAR(4096) と大きくレコード登録後にカラムを追加するととても時間がかかることが判明。幸いデータの流し込みがカラム名指定付きのINSERTだったのでデータ流し込み前にカラムを追加しても問題ないと判断。

CREATE TABLE isuumo.estate
(
   -- 省略
);

ALTER TABLE isuumo.estate
  ADD COLUMN rent_id INTEGER NOT NULL DEFAULT 0 AFTER id,
  ADD COLUMN door_height_id INTEGER NOT NULL DEFAULT 0 AFTER id,
  ADD COLUMN door_width_id INTEGER NOT NULL DEFAULT 0 AFTER id,

その他のクエリーも高速化。UPDATEはCASEで一度に。インデックス追加も一発で。

UPDATE isuumo.estate SET
  rent_id = CASE WHEN rent < 50000 THEN 0 WHEN rent < 100000 THEN 1 WHEN rent < 150000 THEN 2 ELSE 3 END,
  door_width_id = CASE WHEN door_width < 80 THEN 0 WHEN door_width < 110 THEN 1 WHEN door_width < 150 THEN 2 ELSE 3 END,
  door_height_id = CASE WHEN door_height < 80 THEN 0 WHEN door_height < 110 THEN 1 WHEN door_height < 150 THEN 2 ELSE 3 END;

ALTER TABLE isuumo.estate
  ADD INDEX (rent_id, popularity),
  ADD INDEX (door_height_id, rent_id),
  ADD INDEX (door_width_id, rent_id),
  ADD INDEX (rent),
  ADD INDEX (popularity),
  ADD INDEX (latitude);

この時点で15:37:01、スコアは1144です。

MySQL 8.0へのアップグレード(ORDER BY対策)

この時点でもMySQLのCPU使用率が支配的な状況。pt-query-digestで上位のクエリーのEXPLAINを確認すると ORDER BY でインデックスが効いてない。よく見るとDESCとASCの混合が理由と判明。

SELECT ... ORDER BY popularity DESC, id ASC LIMIT ...

MySQL 8.0ではこのような場合でもインデックスを適用できる降順インデックスの存在を思い出してMySQL 8.0へのアップグレードを決意。

wget https://dev.mysql.com/get/mysql-apt-config_0.8.15-1_all.deb
sudo dpkg -i mysql-apt-config_0.8.15-1_all.deb
sudo apt update
sudo apt install mysql-server

これでMySQLはバージョン8.0.21に。

MySQLアップデート後性能が大きく下がってしまったが、調べていくとMySQL8.0でバイナリログが有効に変わり、undoログが記録されるようになったことを確認。この環境のDISK性能が結構低いなどからio改善のため以下を追加。

disable-log-bin
innodb_log_group_home_dir = /dev/shm/
innodb_doublewrite = 0
innodb_flush_log_at_trx_commit = 0

UNDOログもtmpfsに載せようとしたものの、試行錯誤の結果UNDOログは消えると正常に起動しないことから再起動リスクが大きいと判断して触りませんでした。

innodb_log_fileをtmpfsに逃したことと、disable-log-binの効果が大きかった気がします。

なお、 innodb_log_group_home_dirの/dev/shmへの変更はAppArmorで遮られるため適宜調整しています。

/etc/apparmor.d/usr.sbin.mysqld

  /dev/shm/ r,
  /dev/shm/** rwk,

降順インデックス追加

ALTER TABLE isuumo.estate ADD INDEX (rent_id, popularity DESC, id ASC);
ALTER TABLE issumo.estate ADD INDEX (popularity DESC, id ASC);
ALTER TABLE isuumo.chair ADD INDEX (popularity DESC, id ASC);

いい感じにインデックスが効くようになったことを確認。

この時点で16:50:09、スコアは1200です。

空間インデックスと向き合う

この時点でもMySQLのCPU使用率が支配的な状況ですが、一番遅いクエリーはなぞって検索のクエリー。

SELECT id, name, description, thumbnail, address, latitude, longitude, rent, door_height, door_width, features, popularity FROM estate WHERE latitude <= ? AND latitude >= ? AND longitude <= ? AND longitude >= ? AND ST_Contains(ST_PolygonFromText(?), POINT(latitude,longitude)) ORDER BY popularity DESC, id ASC LIMIT ?

ここで空間インデックスの存在を思い出し ST_Contains() で空間インデックスを利用できないかの検討をはじめました。

まず POINT(latitude, longitude) はlatlngから導出できるためpoint型としてカラムに追加。ただし追加するタイミングではNOT NULLにできず、しかしインデックスを追加するためにはNOT NULLに設定する必要がありこんな感じになりました。

ALTER TABLE isuumo.estate ADD COLUMN point POINT;
-- データ登録
UPDATE isuumo.estate SET point=POINT(latitude, longitude);
ALTER TABLE issumo.estate MODIFY COLUMN point POINT NOT NULL;
ALTER TABLE issumo.estate ADD SPATIAL INDEX (point);

しかしこの変更を行ってもSPATIAL INDEXが使われずしばらく悩んだのですが、ググラビリティと試行錯誤を経て SRID 0 を追加すればインデックスが使われることをEXPLAINで確認しました。

ALTER TABLE issumo.estate MODIFY COLUMN point POINT SRID 0 NOT NULL;

わかるかこんなの! なぞって検索の応答時間は平均0.401秒から平均0.063秒と大きく改善しました。

この時点で18:24:13、スコアは1819です。

件数をキャッシュ

この時点でもMySQLのCPU使用率が支配的な状況ですが、pt-query-digestの上位3番目ぐらいに以下のクエリーがきていたので、

SELECT COUNT(*) FROM estate WHERE rent_id = ?

rentのみが条件の場合に絞ってCOUNTをアプリ側でキャッシュすることにしました。

自分はsync.Mapが大好きマンなのでこんな実装になっています。使い方が間違ってたら教えて下さい。

var rentMap sync.Map

        // 初期化
        rows, err := db.Query("SELECT rent_id, count(1) FROM estate GROUP BY rent_id")
        if err != nil {
                ...
        }
        for rows.Next() {
                var rentId, cnt int64
                rows.Scan(&rentId, &cnt)
                rentMap.Store(rentId, &cnt)
        }
        rows.Close()

        // INSERT時のインクリメント
        v, _ := rentMap.Load(rentId)
        p, _ := v.(*int64)
        atomic.AddInt64(p, 1)

        // 取り出し
        if len(conditions) == 1 && hasRent {
                v, _ := rentMap.Load(rentId)
                res.Count = *v.(*int64)
        }

再起動対策のため起動時はmain()とinitialize()の両方でやってます。

この時点で19:30:06、スコアは2070です。

MySQLを2台目サーバに

この時点でもMySQLのCPU使用率が一番高いのですが、nginxとappのCPU使用率も上がってきたことを確認したのでMySQLを2台目サーバに移すことにしました。

この時点で20:07:59、スコアは2612です。

MySQLを3台目サーバに用意するも断念

binlogを出力するとDISK性能が刺さることからレプリケーションは断念、ただあろうことか両方にINSERTすればいいのではという発想でプログラムを改修したものの、おそらくINSERTにかかる時間でタイムアウトが発生しcritical errorを回避できずに断念しました。

今にして思えばJOINがなかったのでテーブルを分ければ良かったのですが、そこまでは思いつきませんでした。分けた場合の性能改善は今後の検討課題です。

ログ出力を抑制

仕上げとしてmysqlのスロークエリーログ、nginxやアプリのアクセスログ出力を抑制してベンチを回しました。

この時点で20:46:31、スコアは2837です。

事前の再起動テストで問題発覚

最後に再起動試験を行ったところ、1台目サーバと2台目サーバの再起動タイミングがずれるとアプリからのDB接続に失敗、systemdのデフォルト設定によりアクセスできなくなってしまう事象が発生しました。

systemdのログからギリギリで以下の設定を追加しています。

/etc/systemd/system/isuumo.go.service

[Service]
StartLimitBurst=999

あぶない。

その他

その他に以下のような改善を実施しています。

  • nginxでgzipを有効に
  • nginxとgolangの間の接続をHTTP/1.1にしてkeepaliveを有効に
  • POST /api/estatePOST /api/chairclient request body is buffered to a temporary file の発生を確認したため、nginxで client_body_buffer_size を調整
  • POST /api/estatePOST /api/chair でのINSERT時に tx.Prepare() してから stmt.Exec()