ISUCON6で準優勝でした

ISUCON 6 にチーム「morimoto組」で参加して、最終スコア 36,067 で準優勝しました。

morimoto組は自分と、会社の新卒1,2年目( kasari , id:moshisora ) という歳の差チームです。

お題

  • 匿名お絵かきサービス
    • ログイン、セッション管理などはない
  • SSE (Server Sent Events) で他のユーザの書き込みがストリーミングで流れてくる
  • 一番前に React のサーバサイドレンダリングをする node のプロセスがいる
  • react, 各言語実装のアプリケーションサーバ, MySQL はすべて Docker で起動している

やー、盛りだくさんでしたね…

スコア推移とやったこと

f:id:sfujiwara:20161024114926p:plain

11:02:53   PASS  942
11:21:28   PASS  1159
11:58:31   PASS  1364
12:31:15   FAIL  253
12:36:34   PASS  1616
12:39:18   PASS  2051  nginxをいれて /api 以下を直接 Perl に (fujiwara)
12:43:40   PASS  3175  並列度が高いのでPerlを200プロセスに (fujiwara)
12:46:41   PASS  3543
12:49:26   FAIL  12
12:53:18   PASS  2816
13:03:36   PASS  3314
13:35:14   FAIL  251
13:47:46   FAIL  251
14:07:14   PASS  3211  pointsをstrokesのカラムにJSONで保持 (kasari, moshisora)
14:09:41   FAIL  0  壊れたSVGを返してベンチマーカーがクラッシュしたらしい
14:10:56   FAIL  0
14:11:25   FAIL  0
14:14:25   PASS  3470
14:15:21   FAIL  0
14:16:38   FAIL  0
14:20:25   FAIL  0
14:24:03   PASS  4697  /img/* で返すSVGをPerlでレンダリング (fujiwara)
14:27:05   FAIL  252
14:29:53   PASS  4781
15:17:25   FAIL  106
15:21:32   PASS  7412  /img/* をRedisにCache(Perlで処理) (kasari)
15:31:52   PASS  6040
16:09:04   FAIL  253
16:10:24   FAIL  253
16:12:32   PASS  8020
16:54:56   FAIL  253
16:58:52   FAIL  253
17:10:31   PASS  9339  /api/stream/rooms SSEをGo + Redis PubSub実装に置き換え (fujiwara)
17:41:33   PASS  15241  React, Perl, Goをisu02で動かして2台構成
17:43:36   PASS  30714  React, Perl, Goを全台で動かす5台構成
17:45:12   PASS  29301
17:48:35   PASS  36067  React, Perl, Goを isu02〜05、isu01にnginx, MySQL, Redisの5台構成

全体の方針

全体の方針としては、以下のようなざっくりとしたスケジュールを組みました。

  • まず 1台でチューニングを進める
  • 複数台構成に1時間、再起動確認などに30分を用意する
  • つまりコードフリーズは 16:30 がデッドライン

チームメイト的には Perl のほうが書きやすい、ということでまず Perl 実装を選択。Perlの初期実装は各言語の中でもだいぶスコアが出にくかったようで、ベンチを回して1000前後。

  • MySQLはDockerから剥がす
  • nginx をいれてログを取りつつ /api は react ではなく直接Perlへ
  • 並列数がだいぶ高いので Perl を200プロセス起動する (無理矢理感ある)

なかなか立ち上がりが早くできず、スコアをあまり上げられずにお昼へ。

アプリケーションの改善

1 Strokeに対して複数保存されるPointsが1点毎に1レコードになっていたので、これはそのままJSONでシリアライズしてStorkeのカラムに保存してしまう(kasari)。既存データもマイグレーションするスクリプトで処理(moshisora)。この時点ではスコアはほとんど変わらないが、その後の改善をしたら効いてくるはず。

/img/ でSVGを返している部分は、初期実装が

という作りになっていたので、ここを直接 Perl で SVG を吐き出すように修正(fujiwara)。

my $svg = qq{<?xml version="1.0" standalone="no"?><!DOCTYPE svg PUBLIC "-//W3C//DTD SVG 1.1//EN" "http://www.w3.org/Graphics/SVG/1.1/DTD/svg11.dtd"><svg xmlns="http://www.w3.org/2000/svg" version="1.1" baseProfile="full" width="${width}" height="${height}" style="width:${width}px;height:${height}px;background-color:white;" viewBox="0 0 ${width} ${height}">};
for my $s (@{ $room->{strokes} }) {
    my ($r, $g, $b, $a) = ($s->{red}, $s->{green}, $s->{blue}, $s->{alpha});
    my ($id, $w) = ($s->{id}, $s->{width});
    $svg .= qq{<polyline id="$id" stroke="rgba($r,$g,$b,$a)" stroke-width="$w" stroke-linecap="round" stroke-linejoin="round" fill="none" points="};
    $svg .= join(" ", map { $_->{x} . "," . $_->{y} } @{$s->{points}});
    $svg .= qq{"></polyline>};
}
$svg .= "</svg>";

ひどいコードだが、動く (4697)。そのあと SVG を Redis に cache するようにして 7412。ここは nginx (OpenResty) から直接 Redis を参照するようにすればもっと伸びたはず、だけど手が回らず未着手。

SSEを処理している部分は初期実装が 500ms sleep してDBに新しいStrokeがあるかどうかをポーリングをくりかえす、という作りで、これは Perl の Prefork server (Starlet) ではプロセスが専有されてしまうので並列度が上がらず不利。

PerlとGoのハイブリッド構成へ

既に15:30なので、手を打つとしたらここが最後の判断ポイント。Goを混ぜることを決断。

  • /api/stream/rooms の SSE だけ Go 実装にする
    • nginxで振り分け
  • 500msのポーリングをやめて、Redis PubSub を使う
    • Perlで保存した新しいStrokeをPublish
    • GoはSubscribeして降ってくるJSONをそのままイベントとして流す

実装としては、以下のようなコード。

  • Redisはgoroutineを起動してそこでsubscribe、イベントが来たらchannelに流す
  • contextを使って3秒で全体をタイムアウトさせる
    • これは出題者にあとで聞いたところ、もっと長くても問題なかったそうです
  • 特にイベントが来なくても 500ms ごとに watcher_count は送信する
    • 最後の case <-time.After(500 * time.Millisecond): のところ
// func getAPIStreamRoomsID(ctx context.Context, w http.ResponseWriter, r *http.Request) {
// ...
    ch := make(chan *redis.Message, 10)
    nctx, cancel := context.WithTimeout(ctx, 3*time.Second)
    defer cancel()
    go func(ctx context.Context) {
        redisClient := redis.NewClient(&redis.Options{
            Addr: os.Getenv("REDIS_HOST") + ":6379",
            DB:   0, // use default DB
        })
        defer redisClient.Close()
        log.Println("starting psubscribe")
        pubsub, err := redisClient.PSubscribe(fmt.Sprintf("%d", room.ID))
        defer pubsub.Close()
        if err != nil {
            log.Println("psubscrie err", err)
            return
        }
        for {
            msg, err := pubsub.ReceiveMessage()
            if err != nil {
                log.Println("recv err", err)
                return
            }
            select {
            case <-ctx.Done():
                return
            default:
                ch <- msg
            }
        }
    }(nctx)
    for {
        select {
        case <-nctx.Done():
            return
        case msg := <-ch:
            var s Stroke
            err := json.Unmarshal([]byte(msg.Payload), &s)
            if err != nil {
                log.Println(err)
                return
            }
            d, _ := json.Marshal(s)
            printAndFlush(w, "id:"+strconv.FormatInt(s.ID, 10)+"\n\n"+"event:stroke\n"+"data:"+string(d)+"\n\n")
        case <-time.After(500 * time.Millisecond):
        }
// ...

たいした変更でもないし1時間あればいけるだろう、と思って一人で書いたものの(fujiwara) 、やはり焦りからかなかなかベンチを通過できず。

17時をまわってしまったので、これで通らなければ Perl のまま複数台構成にするしかないか…というところで最後、kasari に「イベントがなくても 500ms ごとに watcherを送る必要があるのでは？」という指摘をもらってなんとか 17:10 にベンチを通すことに成功！(9339)。

複数台構成へ

ここまでチューニングしてきたホストには netdata をいれていたので、ベンチを回しつつまだまだアプリケーション (React, Perl, Go) がCPUを使っていることは確認済み。

そこで、Dockerで動いていて分散が容易な React, Perl, Go を 2〜5台目のホストで動作させ、1台目は nginx, Redis, MySQL という構成へ。1台目のnetwork転送量がちょっと心配だったけど、そこを詰めている時間的余裕がなかった…

5台構成にしたところ、MySQL が too many connections のエラーを吐いて接続できない現象を確認。

  • my.cnf では max-connections = 10000 になっている
  • 実際に値を見ると 214

...??? と一瞬パニクりかけたが、あこれは systemd から起動して limit が掛かってるな、という見当が付いたので /etc/systemd/system/mysql.service.d/limits.conf を適当に設定して再起動で解決。

[Service]
LimitNOFILE=1000000
LimitNPROC=1000000

1台ずつ再起動テストをして、02〜05 は 01 にあった docker-compose でのOS起動時のアプリケーション起動設定がない、というのも発見したので /etc/systemd/system/multi-user.target.wants/isu.service /etc/systemd/system/isu.service を01からコピーして反映。

結果

最終的には 17:48:35 に記録した 36,067 が提出スコアとなり、運営の再起動テストも通過。2位で準優勝しました。

他チームにスコアが見られる17時までは1万も行かない状態だったので、最後の1時間でだいぶ跳ねた感じでしたが、ここまで書いたとおり決して余裕があって潜行してたわけではありません…

予選も本選も、素晴らしい問題とイベントを提供していただいた出題者の皆様、運営の皆様に感謝します。ありがとうございました！