DSAS開発者の部屋

@methane です。「この技術部には問題がある！」というチーム名で @kizkoh (インフラ担当), @mecha_g3 (アプリ担当) とともに ISUCON 6 に参戦し、予選をトップスコアで通過しました。 恒例のふりかえり記事を書きます。

ふりかえり

残念ながらスコアは記録してないのですが、時系列順にやったことをまとめます。 アプリのコードは methane/isu6q-app で公開しているので、興味がある方はコードを確認してください。

strings.Replacer を使う

使用言語は最初から Go と決めていたのですが、Goの初期実装は遅すぎてタイムアウトで最初からスコア無しでした。 top でアプリのCPUが支配的なのはすぐ判りましたし、コードを読めばなにが遅いのかも一発で判りました。そんなに長くないので関数全体を張ります。

func htmlify(w http.ResponseWriter, r *http.Request, content string) string {
	if content == "" {
		return ""
	}
	rows, err := db.Query(`
		SELECT * FROM entry ORDER BY CHARACTER_LENGTH(keyword) DESC
	`)
	panicIf(err)
	entries := make([]*Entry, 0, 500)
	for rows.Next() {
		e := Entry{}
		err := rows.Scan(&e.ID, &e.AuthorID, &e.Keyword, &e.Description, &e.UpdatedAt, &e.CreatedAt)
		panicIf(err)
		entries = append(entries, &e)
	}
	rows.Close()

	keywords := make([]string, 0, 500)
	for _, entry := range entries {
		keywords = append(keywords, regexp.QuoteMeta(entry.Keyword))
	}
	re := regexp.MustCompile("("+strings.Join(keywords, "|")+")")
	kw2sha := make(map[string]string)
	content = re.ReplaceAllStringFunc(content, func(kw string) string {
		kw2sha[kw] = "isuda_" + fmt.Sprintf("%x", sha1.Sum([]byte(kw)))
		return kw2sha[kw]
	})
	content = html.EscapeString(content)
	for kw, hash := range kw2sha {
		u, err := r.URL.Parse(baseUrl.String()+"/keyword/" + pathURIEscape(kw))
		panicIf(err)
		link := fmt.Sprintf("<a href=\"%s\">%s</a>", u, html.EscapeString(kw))
		content = strings.Replace(content, hash, link, -1)
	}
	return strings.Replace(content, "\n", "<br />\n", -1)
}

今回の問題ははてなキーワード＋はてなスターのようなサービスで、この関数はキーワードの紹介記事に対して他のキーワードへのリンクを生成しつつHTMLエスケープするものです。キーワードは文字数順でソートしているので、最長一致でリンクになります。

キーワードからリンクへの変換が一発でされていないのは、先に変換するとHTMLエスケープで <a> タグまでエスケープされてしまうし、逆に先にHTMLエスケープをするとキーワードを見つけられなくなるからです。（一度これに気づかず一気に変換するようにしてハマりました）

正規表現のビルドと置換のどちらがどれくらいの割合で重いのかまではまだプロファイルを始めてなかったのでわかりませんが、初手からGoらしい最適化を始めてみます。

まずGoの正規表現は遅いので strings.Replacer を使ってキーワードからリンクへの変換をします。 Replacer を構築するのにも時間がかかるので、 htmlify() という関数で毎回構築するのではなく、起動時と、キーワードの追加削除時に再構築をするようにします。（実際にはすでに存在するキーワードの記事に対する修正のケースを見逃していて無駄に再構築していました。これに気づいていたらもっとスコア上がったはず…）

var (
	mKwControl sync.Mutex
	kwdList    KeywordArray

	mKwReplacer                  sync.RWMutex
	kwReplacer1st, kwReplacer2nd *strings.Replacer
)

func updateReplacer() {
	reps1 := make([]string, 0, len(kwdList)*2)
	reps2 := make([]string, 0, len(kwdList)*2)
	for i, k := range kwdList {
		if k.holder == "" {
			k.holder = fmt.Sprintf("isuda_%x", sha1.Sum([]byte(k.Key)))
			kwdList[i].holder = k.holder
		}

		reps1 = append(reps1, k.Key)
		reps1 = append(reps1, k.holder)

		reps2 = append(reps2, k.holder)
		reps2 = append(reps2, k.Link)
	}
	r1 := strings.NewReplacer(reps1...)
	r2 := strings.NewReplacer(reps2...)
	mKwReplacer.Lock()
	kwReplacer1st = r1
	kwReplacer2nd = r2
	mKwReplacer.Unlock()
}

func AddKeyword(key, link string) {
	k := Keyword{Key: key, Link: link}

	mKwControl.Lock()
	kwdList = append(kwdList, k)
	sort.Sort(kwdList)

	updateReplacer()
	mKwControl.Unlock()
}

func ReplaceKeyword(c string) string {
	mKwReplacer.RLock()
	r1 := kwReplacer1st
	r2 := kwReplacer2nd
	mKwReplacer.RUnlock()
	x := r1.Replace(c)
	x = html.EscapeString(x)
	return r2.Replace(x)
}

AddKeyword はキーワードをポストしたときに、 ReplaceKeyword は htmlify から呼ばれます。これで NewReplacer を呼び出す回数を大幅に削減することができました。

この変更を投入するタイミングで、 MySQL に接続するときに '127.0.0.1' からの接続が許可されていないというエラーがでるようになって（何もしてないのに壊れた追記: 秘伝のタレでskip-name-resolveが入ったのが原因の模様） Unix Domain Socket を使うようにしました。 @kizkoh による nginx や MySQL の設定 (静的ファイルを nginx で返す等) や、初期実装にあったバグを潰したりして、14:00すぎに12万点を出しました。

isutar を isuda にマージ

これは @mecha_g3 に任せた部分です。 isutar と isuda がお互いにJSON APIを使ってやり取りをしている部分があって、2つのアプリとMySQLが1台のマシンに乗っている以上完全に無駄なので全部1つにまとめました。スコアを記録してないのですが順当に性能アップしたはずです。

これを投入してベンチをかけるときにハマったのが、DBコネクションのデッドロックです。もともと2コアの1台のマシンなので、DBへの接続は4本も要らないだろうと思いつつ、念のために8本にしていました。ところが、次のようなコードが原因で8本あっても足りなくなってしまいました。

	rows, err := db.Query(fmt.Sprintf(
		"SELECT * FROM entry ORDER BY updated_at DESC LIMIT %d OFFSET %d",
		perPage, perPage*(page-1),
	))
	if err != nil && err != sql.ErrNoRows {
		panicIf(err)
	}
	entries := make([]*Entry, 0, 10)
	for rows.Next() {
		e := Entry{}
		err := rows.Scan(&e.ID, &e.AuthorID, &e.Keyword, &e.Description, &e.UpdatedAt, &e.CreatedAt)
		panicIf(err)
		e.Html = htmlify(w, r, e.Description)
		e.Stars = loadStars(e.Keyword)
		entries = append(entries, &e)
	}
	rows.Close()

このコードはトップページのハンドラーの一部です。 for rows.Next() ループが終了して rows.Close() が呼ばれるまでDBの接続を握るのですが、このループ中の loadStars(e.Keyword) の部分が中でさらにSQLを呼び出しています。 この状態で、 top ページに8個並列でアクセスが来てループの外側のクエリを実行すると、8本の接続を使い切った状態になり、どの goroutine も内側の loadStars() でDB接続を無限に待ってしまうことになります。

落ち着いて考えればすごく当たり前のことなのですが、最初は rows.Close() を呼んでない場所がどこかにあるんじゃないかと探し回ったり、この形のネストがまずいことに気づいたときも「でも1goroutineあたりのDB接続数が2倍になるだけだから、その程度の余裕は見込んで8本にしたんだけどなあ。」と考えてしまったりしてしまいました。

結果、この問題の対策もちゃんとネストを潰すのではなく、単にコネクションプールの数を倍の16に増やしただけです。ベンチマーカーがどんどん並列度上げてくるタイプだったらこれでも死んでました。

教訓として、 rows.Next() ループ内でネストしてクエリを実行するのは単に必要な接続数が倍になる以上の凶悪さを持っているので、 rows.Close() までの処理は単純にクエリ結果のフェッチだけにしましょう。

Replacer の構築を zero time cache 化

プロファイルを取ってみたところまだ Replacer の構築が重いので、個人的に zero time cache と呼んでいるイディオムを使って安全にキャッシュをしてみます。次のコードを見てください。

var (
	mKwControl sync.Mutex
	kwdList    KeywordArray

	mUpdateReplacer sync.Mutex
	repLastUpdated  time.Time
)

func AddKeyword(key, link string) {
	k := Keyword{Key: key, Link: link}
	mKwControl.Lock()
	kwdList = append(kwdList, k)
	mKwControl.Unlock()
	updateReplacer()
}

func updateReplacer() {
	now := time.Now()
	mUpdateReplacer.Lock()
	defer mUpdateReplacer.Unlock()

	if repLastUpdated.After(now) {
		return
	}
	repLastUpdated = time.Now()

	reps1 := make([]string, 0, len(kwdList)*2)
	reps2 := make([]string, 0, len(kwdList)*2)

	mKwControl.Lock()
	kws := kwdList[:]
	mKwControl.Unlock()

	sort.Sort(kws)
　　// ... 以降 Replacer の構築処理
}

mUpdateReplacer と repLastUpdated が追加した変数で、 updateReplacer() の repLastUpdated = time.Now() までがイディオムになっています。

例えば、キーワードA, B, C がほぼ同時に追加されたとします。

1. まずAが最初にロックを取得して、 repLastUpdated = time.Now() を実行して Replacer の構築を始めます。
2. 続いてキーワードBとCがともに mUpdateReplacer.Lock() で停止します。ロック直前に取得した now は (1) で更新した repLastUpdated よりも未来の時間になります。
3. キーワードAの Replacer 更新が終了し、 mUpdateReplacer が開放されます。キーワードBを処理していた goroutine がそのロックを取得します。
4. ロック取得前に取得した now が repLastUpdated よりも新しいので、 if repLastUpdated.After(now) が真になりません。なので Replacer を再構築します。キーワードAを更新したときの kwdList にキーワードBは入っていなかった（厳密にはタイミング依存で入っていた可能性もある）ので、これは必要な処理です。
5. さらにキーワードBの Replacer 更新が終わり、キーワードCが mUpdateReplacer のロックを取得します。今度は if repLastUpdated.After(now) が真になるので、 Replacer の再構築はスキップされます。 (4) で Replacer を再構築したときには確実にキーワードCも kwdList に入っていたので、スキップしても安全です。

この説明を一度読んだだけでは理解できないかもしれませんが、ぜひじっくりとコードと見比べて理解してみてください。 このイディオムはISUCONだけではなく、実際にGoで高性能なサーバーを書くときに大変便利です。

また、例えば MySQL が複数のトランザクションを一度の fsync でコミットするグループコミットなど、「同時に実行される重い処理をバッチ化する」というのは並列処理のデザインパターンと呼んでも良いくらい汎用的だと思うのですが、どなたかこのパターンの名前をご存知でしたら @methane 宛の Tweet などで教えてください。

仕上げ

まだ top ページのハンドラーが重かったので、再び zero time cache パターンを使ってさらにトップページの内容の取得を効率化します。

ただしこのときは効率より実装の手早さを優先して、 zero time cache パターンをトップページのハンドラ内に直接実装してしまいました。着実には性能向上しましたが、これもキーワードの更新側に処理を持っていけばもっと劇的な性能向上が見込めたはずです。

最後に、アプリの環境変数で GOGC=400 を設定し、プロファイルやモニタリングやnginxのアクセスログを切り、ベストスコアを出すまで enqueue を数回実行して終了しました。

考察

POST /keyword のアクセスがキーワードの追加だけではなく更新にも使われていることを見逃していて、一番重い Replacer の再構築を必要以上に実行してしまっていたのが悔やまれます。

また、上に書いたようにトップページの内容の更新も、 GET / ではなく POST /keyword で行えばもっと劇的なスコアアップができたでしょう。

さらに、非ログインユーザーのトップページを静的ファイルに書き出してしまって nginx に直接返させるのも、ISUCONで頻出の攻略法で事前に判っていたはずで、実装する時間もあったはずなのにやるタイミングを逸してしまいました。

これらを全部できていれば、ベンチマーカーの実装次第ですが、倍の50万点の可能性もあったかもしれません。

感想

今までは毎年予選は一人で戦って勝ち抜いてきたのですが、去年の予選のボリュームが本戦と同じくらいあってキツかったので、今年は予選からチームで戦うことにしました。

「直したはずのバグがこっちのブランチでは直ってなかった」「プロファイルが違う場所のバイナリ／ソースを参照してたかもしれなくてくてアテにならない」系のトラブルはあったものの、自分がアプリを書くときに心配事を忘れて集中できたり、逆に実装を任せてる間に自分は休憩したり落ち着いて見直しをしたりできて、精神的な負荷が大幅に減り、余裕を持って優雅に戦えたと思います。

一方で、Azureに慣れていなかったことや、14時過ぎに取った初めての0点以外のスコアがその時点の断トツトップで、そこからもほぼずっと2位のダブルスコアをキープしていたこともあって、保守的になりすぎて全力を出し切れたとは言い難いです。

本戦では全力を出せるように、もう少しチームワーク練習や環境構築の練習を重ねて行きます。

それでは、決勝進出者のみなさん、決勝でお会いしましょう。 運営・出題者のみなさんはお疲れ様でした。決勝も引き続きお願いいたします。