ISUCON9決勝参加記 (チーム名: ようするにメガネが大好きです)

ISUCON9決勝に参加して fail しました。原因は自分の書いたバグで大分凹んでいます。ピークスコアは14991点でした。

やったこと

自分がやった分だけ。大したことはやれていません。

• pprof, stackdriver trace の導入
• Docker compose があったのでローカル開発できるか試してすぐやめた
• reservation の N+1 解消 ref
• distance_fare_master のオンメモリ化 ref
• reservation テーブルの arrival, depature カラムに駅名ではなくIDを入れるようにした。これで getAvailableSeats で station との join が消せた。 ref

失敗したこと

fail の原因になったバグはこんなコードです。

   for {
        _, err := dbx.Exec("select 42")
        if err != nil {
            log.Println(err)
            time.Sleep(time.Second)
        }
        break
    }

接続ができなくても Sleep したあと continue してないですね。。。。これでDBより先にアプリが起動したら、 master データをDBから持ってくるコードが動かずに fail してしまいました。

cancel を bulk 化する前にいったん遅延するようにしてみたところエラーが起こり revert しました。しかしこれはどうやら別の原因だったようです。

/initialize で負荷を指定できることに気づいておらず（大ポカ）、17:20頃に教えてもらって試したら cancel がたまりすぎてエラーに。慌てて bulk を実装始めるもヌルポエラーを出してしまい、修正できないまま再起動試験に。

あと、 makki_d が train_master, seat_master をオンメモリ化してくれている間に座席のロックの粒度を下げたり、席が空いているかどうかを高速にチェックできるようにする方法を考えようとしていたのですが、全然頭がクリアに働かず頭の中をぐるぐるするだけで何もできませんでした。この時間にキャンセルの bulk 化とか落ち着いてレギュレーション読むとかできればもっと色々できたはず。

感想と反省

意味不明の print だらけでログがぐちゃぐちゃになるクソコード、プライマリキーが存在せずに駅名等が全て文字列で入っているテーブル、とにかく問題外な初期実装でした。（褒め言葉）

家庭の問題があってメンタルも睡眠時間も不足気味で実力を発揮できないばかりか致命的なミスをしてしまい本当に悔しいやら情けないやら。来年もできれば同じチームで参加して挽回したいです。

ISUCON9予選参加記 (5位通過)

mapk0y (インフラ), makki_d (アプリ) とともに「ようするにメガネが大好きです」というチーム名で参加し、2日間を通して5位のスコアで通過しました。

選択言語は Go です。ソースコードはこちらで公開しています。 GitHub - methane/isu9q

POST /buy 初期対策

CPUプロファイルを見ると login の bcrypt が重いのはすぐに目に付きます。過去にもあったのでsha1など軽いハッシュへの置き換えも考えましたが、面白くないのでこれはしなくても攻略できるようになっているはずだと出題者を信じて無視します。 最終的に login は残りの2台に分散するだけで一切手を加えずに乗り切りました。

アクセスログを見ると明らかに POST /buy が重く、 campaign を増やしたときのマッコネ (MySQL の Too many connections) やベンチマークのタイムアウトエラーの主因にもなっていました。とりあえず最初はシンプルにGoの段階で排他してやります。

+var itemMutex sync.Mutex
+
+func itemLock() func() {
+   itemMutex.Lock()
+   return itemMutex.Unlock
+}
+
 func postBuy(w http.ResponseWriter, r *http.Request) {

...


+   defer itemLock()()
+
    tx := dbx.MustBegin()
 
    targetItem := Item{}
    err = tx.Get(&targetItem, "SELECT * FROM `items` WHERE `id` = ? FOR UPDATE", rb.ItemID)

外部APIエラーとの戦い

しかし外部APIサーバーが 502 Bad Gateway を大量に返すようになってしまって fail が続きます。

502-bad-gateway

答えられないということは、障害ではなくて仕様なのでしょう。(追記: 障害だったようです。なので私達のチームはこのエラーのために多くの時間を浪費することに。) ここからAPIサーバーとの戦いが始まります。

マニュアルを読んでもレートリミットやバッチ化呼び出しなどの仕様はなく、 tcpdump を使って確認してもヘッダは削られまくっててやはりレートリミットに関するヘッダなどのヒントはありません。

この API は購入と配送に関するもので、１取引あたりの最低呼び出し回数は決まってます。とりあえず GET /transaction のなかからの呼び出しを削除してその時点の暫定1位はゲットしたものの、その後はずっとAPIの呼び出し方を工夫していました。

mapk0y が chocon という API 呼び出し用の proxy サーバーを入れてくれ、 makki_d がその対応や分散などをしてくれました。

呼び出しの並列度を下げても、すこし間隔を入れてもエラーが出ます。 Bad Gateway 以外に bad IP もあるみたいなので、API呼び出しを３台から分散して行うようにしてみたのですが効果は微妙です。

マニュアルにベンチマーク中以外に使える開発用APIサーバーが載っていたのでそこに curl でアクセスしてみて、使い方がわかったところでそれを雑に while : で回したらエラーが出ないことに気づきました。それで chocon の keep alive を切ってもらったのですが、残念ながらエラーはまだ出たので最終的に makki_d にリトライを入れてもらってゴリ押ししました。

結局502エラーの数が安定しないまま、どの対策がどれくらい効果があるのかを確認できないままでした。ベンチを回すばかりでなく、もうちょっと直接APIサーバーを色んな方法でアクセスして bad gateway や bad ip エラーの発生条件を調べられなかったのが反省点です。（ブラックボックスのリバースエンジニアリング、好きな人は大好きだけど、そうじゃない人は逃げがち）

その他のチューニング

上で紹介した雑なロックは次のように書き換えて別々の商品は並行して買えるようにしました。

var itemMutex []sync.Mutex = make([]sync.Mutex, 100)

func itemLock(i int) func() {
    n := i % 100
    itemMutex[n].Lock()
    return itemMutex[n].Unlock
}
...
    defer itemLock(int(rb.ItemID))()

これでも /buy のタイムアウトが発生します。商品が売れたあとに、API呼び出しを含む長いロックを待ってた人が１人ずつ売れてしまったことを確認するようになっていたので、売れた商品をキャッシュするようにするとタイムアウトが解決しました。

そもそも売上がスコアに直結するのに同じ商品に客が集まり過ぎなので、これをバラせないかなと思って新着商品の順番をページ内でシャッフルしてみたところベンチマーカーに怒られたので諦めてしまいました。あとから考えるとここがスコアに直結するので諦めたのは早計で、 /buy でロック中の商品（APIエラーで売れない可能性がある) を sold 扱いで表示するとか、隠すとか、もうちょっと粘るべきだったと思います。

この辺は実際のアプリ開発なら自分から提案できるんですが、あくまでもブラックボックスのベンチマーカーがルールのISUCONでは提案ができないので、ベンチマーカーが何を許すかの試行錯誤を面倒がってしまいます。。。チューニングがしたいんであってブラックボックスのリバースエンジニアリングがしたいんじゃないんですよね。。。

他には、 items テーブルの seller_id, buyer_id, created_at カラムにインデックスを張ったり、設定をいじったりしていました。アプリ側で一番大きい変更 (user の N+1 解決) は makki_d がやってくれました。

感想

去年の予選は上位スコアを出しつつも重いAPIの対策をおろそかにしていたために終盤スコアが乱高下し結果敗退しました。

その反省から、今年は12時台に 502 エラーが大量発生したあとは、頑張ってチューニングしてエラーで fail するという結末を避けるために穏当なチューニングだけで手堅く勧め、エラー率の低い（スコアが安定する）状態で勝ち進むことができました。

一方でAPIエラーの発生条件の解析や、商品リストをどう改造するとベンチマーカーがエラーを出すかの解析など、役割分担的に僕がするべきだったところの解析がちゃんとできていなかったのが悔やまれます。これを突破しないと実力での優勝はできないので、決勝では面倒臭がらずもっと覚悟と気合を入れていきます。

設問とインフラは良かったと思います。特に Go の初期実装が (Sinatra風の無名関数を直接ハンドラに登録するやりかたでなく) ちゃんとAPIごとに名前のある関数を用意しているのでスタックトレースやプロファイルも読みやすかったですし、ベンチマーク待ちも（17:20以降は完全に手を触れなかったのもあり) ほぼ感じませんでした。

一日目の Twitter を見てトラブルを覚悟していたのですが、初回起動もすぐ終わり、インスタンス作り直しが必要なミスもしなかったのでとても快適に競技に集中することができました。ありがとうございます。

(PEP 584) dict + dict 演算子追加について

注意：この記事は議論中の機能について紹介し自分の考えを述べるものです。 Python 3.8 で追加されるらしいよ！みたいな拡散はしないでください。

Python-ideas で dict + dict が提案され、PEPになった。

www.python.org

d3 = d1 + d2 の動作は、 d3 = {**d1, **d2} や d3 = d1.copy(); d3.update(d2) と同じになる。

もともとの提案では + と | の両方が考慮されていたのだけれども、 sequence + sequence は交換法則を満たさず、 set | set は交換法則を満たすので、交換法則を満たさない dict + dict は | より + のほうが良いだろうという Guido の一言が PEP 化の直前にありこの方向になった。他には | が + よりも初心者に優しくない記号だからなんて理由もあった。ただし、Guidoはその後やっぱり | も良いかもしれないと発言しているので今後は分からない。

追加のモチベーションについて

• seq + seq や set | set があるのに dict を結合する演算子がないのは不公平。
• d3 = {**d1, **d2} はわかりにくい。
• d3 = d1.copy(); d3.update(d2) は複数の statement に分かれるのが嫌。 expression で書きたい。

僕の考え

演算子を abuse するにしても、 seq + seq や set | set はそれぞれ abuse するのに妥当な演算子を選んできた。 seq + seq は、数学未満の算数で考えたとき、 concatenation は「足し算」が現れる場面の1つであろう。また seq + seq + seq と seq * 3 が同じになる。 set | set はもちろん∪の代わりに、ビットごとのOR演算子 | を採用したものだ。集合の和とビットごとの論理和の振る舞いには強い関連がある。

一方で、 dict.update() は seq + seq や set | set に比べて + や | 演算子との関連度が低い。（この関連度の低さをML上でうまく英語で説明できなくてつらい。） dict.update() は dict の key に注目したときに set | set と同じふるまいをする分、 seq + seq よりも set | set に近いふるまいだ。

言語設計は判断の積み重ねで、その中で生まれてきた一貫性は、たとえ意図せず生まれた偶然の産物であったとしても、その言語のユーザーに指針を与え、学習速度を助ける。 |が交換律を満たしていたというのも、振る舞いから適当な演算子を選んでいたというのも、最初から絶対的な指針があった上でこうなっているわけでは無いものの重要な一貫性だ。さてどっちの一貫性を壊す？

もしここで大きな決断をするのであれば、 + を「コンテナ型の連結演算子（連結時の振る舞いはコンテナ依存）」として一般化してしまうのが良いと思う。その場合は set + set も set | set のエイリアスとして追加する。

いくつかの演算子オーバーロードがある最近人気の高い言語を調査してみた結果、「コンテナ型の連結」に共通の演算子を割り当てている言語があった。 Kotlin は (| に対する演算子オーバーロードがないという事情もあるが) + を利用していて、 Scala は ++ を利用している。

破壊的変更メソッドと演算子について

この提案に賛同する人のモチベーションの一つが、 Python の update() メソッドが self を返さず、 func(d1.update(d2)) や (d1.copy().update(d2))のようなことができないという物がある。

この背景には、実行効率や安全さを１つの複雑な書ける事よりも優先するという設計上の決定がある。そのために Python は、半ば意図的に、いくつかの場面で簡単な処理でも1つずつ文にしないといけないという面倒さを押し付けている。

僕は、言語を使うときの何かの面倒さは、なにかのメリットを得るための引き換えだと、わりとすんなり許容するほうだ。(Goのループとか) だから Python の dict.update() も、この利用頻度なら別に文を書かないといけなくても大した問題じゃないと思っている。

一方でそういうのがとても嫌な人がいることも理解している。しかし、演算子というのはメソッドよりも言語設計上重要な要素のハズで、メソッドの安全性のための設計による面倒さを回避するために演算子を abuse しようというのは、どうも気持ち悪く感じる。d3 = d1.updated(d2) とかのメソッドを足すだけで我慢してほしい。

MySQL Connector/C の代わりに MariaDB Connector/C を使う

mysqlclient の Windows 版バイナリ wheel を作るために、以前は MySQL Connector/C を使っていたのですが、しばらく問題があって利用できませんでした。

• static link library が提供されない
• ビルドの仕方がよくわからん。ドキュメントもない。
• TLS と sha256_password / caching_sha2_password のために OpenSSL がいる

ちなみに、 MySQL Connector/Python の Windows 版は site-packages 直下 (つまりグローバル) に OpenSSL の dll を含めて必要なものを全部ぶちまけるようになっています。ロックだ。それと同じロックな手段をとると当然衝突します。

そこで MariaDB Connector/C の動向をウォッチしていたのですが、最近色々な条件が揃ったので、 mysqlclient の Windows 版は MariaDB Connector/C を使うようにしました。

• static link をサポートしている
• ビルドの仕方が(一応)ドキュメントされてる
• TLS も sha256_password や caching_sha2_password も OpenSSL ではなく Windows API を利用しているので OpenSSL の同梱が不要。

MariaDB Connector/C は Windows 版バイナリを配布しているのですが、 caching_sha2_password などのプラグインが DLL の状態で同梱されているので、完全 static link したい場合にはちょっとあいません。

wiki に完全 static なライブラリのビルド方法を残しておいたので、必要な方は参考にしてください。

go-sql-driver/mysql の QueryContext でコンテキストをキャンセルしたら race が起こる

タイトルの通り、 QueryContext の第一引数に渡した Context を、 Rows.Close() を呼び出す前にキャンセルすると、 race が起こる可能性があります。

修正する pull request を作成したのですが、メンテナが作ったプルリクエストは他のメンテナのレビューなしにマージしてはいけないというルールがあるのでまだマージしていません。なので、 QueryContext を利用するときは注意してください。

github.com

問題になるコード

Rows.Scan() の引数の型が *sql.RawBytes (sql.RawBytes の定義は type []byte RawBytes) だった場合、受け取った []byte の中身が他の goroutine から書き換えられることがあります。

rows, err := db.QueryContext(ctx, "select ...", ...)
if err != nil {
    // ...
}
defer rows.Close()

for rows.Next() {
    var sql.RawBytes
    err := rows.Scan(&buf)
    // どこかのタイミングで ctx がキャンセルされると、
    fmt.Println(buf) // buf の中身が他の goroutine から書き換えられる
}

背景

database/sql の設計は、 driver の API は1つの接続だけを扱う（コネクションプール部分は全て database/sql が解決する）、そしてその1つの接続に対して並行で driver の API が呼ばれることはない、ようになっています。

また、 rows.Scan() が sql.RawBytes を出力する場合、その参照先の部分は次の rows.Next() か rows.Close() 以降はドライバが再利用できるようになっています。これは受信バッファの中身を直接スライスで返すことで余分なアロケートとコピーを減らすためです。

コンテキスト対応が入るまではこれでうまくいっていました。しかし、 database/sql がコンテキストに対応する時に、コンテキストのキャンセルを別 goroutine で監視して、アプリケーションからの rows.Close() や rows.Scan() を待たずにドライバー側の rows.Close() を呼び出すようにしてしまったのです。

Go 1.10 の changelog

結果として次のような状況になりました。

• rows.Scan() が返した sql.RawBytes (type []byte RawByte)は受信バッファの中を直接参照しています。アプリケーションは次の rows.Next() か rows.Close() を呼び出すまではその中身を合法的に読むことができます。
• ドライバは rows.Close() や rows.Next() が呼ばれた場合、前回の Scan() で返した []byte の中身を破壊していいので、送受信バッファとして再利用します。
• database/sql はコンテキストがキャンセルされると別 goroutine からドライバ側の rows.Close() を呼び出します。

正直、なんてことしてくれたんだ！って感じです。アプリケーションが rows.Next() を呼ぶまで待ってくれたらいいのに。なんでわざわざ別 goroutine で。。。

たぶん一刻も早くキャンセルしたかったんでしょうが、MySQLでは百害あって一理ありません。 MySQL でクエリのキャンセルは難しいのでまだ実装してないし、たとえ実装していたとしても、 rows.Next() が一回でも呼ばれているということはクエリの実行はすでに終わっています。 rows.Next() を待たずにキャンセルするメリットが現在も将来も一切ありません。

2019-04-03 追記: sql.RawBytes を使わなくても race が起こる

ユーザーコードに直接受信バッファの中身を参照する []byte が渡されるのは sql.RawBytes を利用したときだけです。

しかし、 database/sql の sql.Rows.Scan() は、 driver.Rows.Next() が返した値と Scan の引数の間の変換処理をしています (convertrows)。この変換処理は driver.Rows.Next() が返した受信バッファ内を直接参照する []byte から string を作ったり、新たな []byte を作ってそこにコピーしたりしています。

タイミング悪くこの変換処理中にコンテキストがキャンセルされた (厳密には database/sql 内の監視 goroutine がコンテキストのキャンセルを検出して driver.Rows.Close() を呼び出した) 場合は、ユーザーコードで sql.RawBytes を使っていなくても race が発生します。