ISUCON11 予選おつかれさまでした。

ここ数年は参加者として予選敗退を繰り返してきたのだけど、今年はちょっと違う関わり方をしてみるか、と思い「参考実装の移植」に立候補してみました。

Node.js担当として採用していただき、ちょっと不安もあったのでid:hokaccha 氏にレビュアーとしてついてもらって、言語移植チームとして加わりました。

ISUCON11予選おつかれさまでした。今回は言語移植チームとしてNode.js実装を担当し、その他バグ直し太郎として幾つかの言語の実装にcontributeしました
— すぎゃーん💯 (@sugyan)August 22, 2021

Node.js 実装

中身としては素朴なexpress のアプリケーションで、TypeScriptで実装しました。mysql clientにはmysql2/promise を使うことで async/await で簡潔に書けそうだったのでそれでやってみました。

www.npmjs.com

行数としては元実装の Go 1262行に対し 1243行とほぼ同等、それなりに丁寧に型定義などを書きつつ元実装を忠実に再現したものになったかと思います。

昨年のisucon10のリポジトリなどをとても参考にしつつ、今回の自分の実装が未来の実装者の参考にもなるように、と気をつけて書いたつもりです。

1組だけですがNode.js実装で本選にも残ったチームも居たようで良かったです。

isucon.net

開発環境

移植作業をする時点で既にGoの参考実装やbenchmarker、そして開発環境がある程度できあがっていて、作業を進めやすくてとても助かりました。このへんは作問チームのレベルの高さをすごく感じました。

複数のコンポーネントからなるそれなりに複雑なアプリケーションながらも、docker-compose.yml やMakefile がしっかり用意されていて、そこに自分の実装する言語用の環境を用意できればコマンド一発でWebアプリが起動できるし benchmarkerを走らせたりもできる。benchmarkerは-no-load オプションで負荷走行前のアプリケーション互換性チェックシナリオを走らせるので、まずはそこがすべて通るようになれば大体の移植は出来ていると判断できる、という具合。

勿論CIでもテストが走るようになっていて、それらが通っていてさらに作問チームメンバーやアドバイザリーからレビューを受けた上でapproveされたらmergeできる、といったルールもしっかり整備されていて、とても体験の良い開発環境でした。

実装についての疑問や相談もSlack上でいつでも作問メンバーが素早く回答してくれて、とにかく素晴らしいチームだな、と思いました。このチームの人たちと同じプロジェクトに取り組めたというだけで今回応募してみて本当に良かったと思っています。

Contributions

Node.jsの実装も一通り出来たところで他の言語実装も出揃ってきていたので試しに動かしてみて、細かいエラーが出ていたところを修正したりもしました。

「オレでなきゃ見逃しちゃうね」的な細かいものとか

あとはPerl書ける人が少なかったようなので「いちおう私も多少Perlの経験あるのでレビューくらいなら」とちょっと見てみたり

feat(perl) initial implementation by kfly8 · Pull Request #1099 · isucon/isucon11-qualify · GitHub

benchmarkerの細かい挙動について指摘したりライブラリのバグをついたりもしました

あと実際に本番前々日くらいにサーバ上で各言語の初期実装に対してbenchmarkしてみたところ、何故かNode.jsがGo実装よりも2倍以上高いスコアが出た(！)という謎現象が見つかり、調査の結果それはNodeがたまたまbenchmarkerの秘孔をつく動作をしていたことが分かり修正されたのですが、そういうのを見つけることが出来るという点でも複数言語での移植は意義があるのだなぁと思いました。

tagomorisバグ

余談。

Perlの実装を手伝っているときに、benchmarkerを走らせていると何故か予期せぬところで401 を返していてチェックが失敗するという現象が起きていた。

401 ってことはcookie-sessionまわりだよな〜でも特に変なところとか無いはずだしな〜とid:kfly8 氏と一緒に見ていて、ところでPlack::Middleware::Session::Cookie のsecret は"tagomoris" とかじゃなくて今回は"isucondition" (もしくはSESSION_KEY環境変数) で統一するって話じゃないですかと指摘してそこだけ直してもらった

https://github.com/isucon/isucon11-qualify/pull/1099/commits/57f165c73f92bac69a449912d8cb8118b05bf38c

 builder {     enable 'ReverseProxy';     enable 'Session::Cookie',-        session_key => $ENV{SESSION_KEY} // 'isucondition_perl',+        session_key => 'isucondition_perl',         expires     => 3600,-        secret      => 'tagomoris';+        secret      => $ENV{SESSION_KEY} || 'isucondition',     enable 'Static',         path => qr!^/assets/!,         root => $root_dir . '/../public/';

この変更を入れたら先述の401 のエラーが出なくなり…。

「えっcookie の secret key を"tagomoris" から違う文字列に変えただけでバグが直ったの！？」と混乱した、という出来事。

種明かしをするとこの変更はsecret 指定の末尾が; だったのを, に変えてしまっているというミスが含まれていて。

-MO=Deparse してみると変更前は

&builder(sub{    enable('ReverseProxy');    enable('Session::Cookie','session_key','isucondition_perl','expires',3600,'secret','tagomoris');    enable('Static','path',qr"^/assets/",'root',$root_dir .'/../public/');$app;}

というものだったのが変更後は

&builder(sub{    enable('ReverseProxy');    enable('Session::Cookie','session_key','isucondition_perl','expires',3600,'secret','isucondition', enable('Static','path',qr"^/assets/",'root',$root_dir .'/../public/'));$app;}

と解釈されてしまう。続くStatic middleware をenable した結果がSession::Cookie の引数に並べられる形になり、内部ではその値は無視されるのだろうけど、何が起こっているかというと「enable が呼ばれる順番が変わる」。

ここでまた別の事象として、benchmarkerが「/assets/ 以下に含まれるファイルをGETした際にSet-Cookie ヘッダが含まれているとそれによってbenchmark scenarioを回しているagentが別人になってしまいその後のリクエストで401 になってしまう」というバグがあった。

つまりこのpsgiでは先にSession::Cookie をenable しているとその後に呼ばれるStatic のファイルたちにもSet-Cookie がつくことになり、そのbenchmarkerのバグをつくことになってしまっていた。"tagomoris" を修正した際に間違えて; を, に変えてしまたことにより意図せずStatic →Session::Cookie の順にenable する形に変わっていてそのバグをつかないように変更されたのでエラーに遭遇しなくなった、というオチでした。

奇妙な挙動にとても戸惑ったけど複数の不具合が密接に絡んで起きた奇跡のような現象でした。という話。

いやー数年ぶりに書いたけどやっぱりPerlむずかしい…。一晩で解決できたのも奇跡だったのかもしれない