TokyuRuby会議13に行ってLTやって飯王を(また)とった

今年もまた行われたTokyuRuby会議に、先日のRubyKaigiでLTやったMaccroのネタをまた持って参加してきた。

TokyuRuby会議13 - Regional RubyKaigi

が、Maccroは進捗があまりなく、どっちかというと今回もサントリーさんのスポンサーによるビール飲み放題があるので、それにあわせてガッと食べられる食べ物を持っていったのが結果的にメインになってしまった感。
なんにせよ大変楽しいイベントでした。運営のみなさん、会場提供のSpeeeさん、ビール飲み放題のサントリーさん、ありがとうございました。

食べ物のはなし

去年は渾身の一品で狙いに狙って飯王をゲットしたのもあって、今年は少し前まではまあ頑張らなくていいかなーと正直思っていたんだけど、いろいろあって結構な額のふるさとアレをアレした結果、最近慢性的に冷凍庫が肉等で溢れる事態となっていた。
これがマジで困るので、しょうがないからそのキロ単位の肉塊をいくつか投入しておいしくして持っていけばいいのでは? というアイデアが降臨する。しかもAsakusa.rbの花見を切っ掛けにイノベーションのアイデアが降臨したのでそれも投入。結果として、単品飯王をぶっちぎりでいただき、かつ(他の2品もあって)合算飯王までゲットしてしまった。完全勝利だ。

ほかほか焼売をデプロイしました #tqrk13 pic.twitter.com/np0L3zcpeo

— tagomoris (@tagomoris) June 29, 2019

#asakusarb 花見の知見を活用し化学の力で火器が使えなくても蒸し料理を提供するモリスさん #tqrk13 pic.twitter.com/iXT4tfEavf

— ジョーカー 参戦！！ (@joker1007) June 29, 2019

豚しゃぶ！ #tqrk13 pic.twitter.com/UVWksgWwST

— tagomoris (@tagomoris) June 29, 2019

手羽先やわらか煮！ #tqrk13 pic.twitter.com/5ZUizX6E90

— tagomoris (@tagomoris) June 29, 2019

特に焼売は超ウケがよくて、ほかほかと湯気を上げてサーブしていたらサントリーさんのスタッフの方が「おなかがすいてきたんですが……」といらしたので、人数ぶん持っていってもらったりしてた。いつも座ってたらビールが運ばれてくるのだが、これで多少でもお返しができただろうか。

焼売はもちろん現地で蒸し上げたわけではなくて、実際には自宅で蒸したあと現地では蒸すことでほかほかに加熱する、というくらい。ただそれで十分おいしいくらいに温かくなった、はず、というかいま気付いたが俺は当日現地でひとつも食べていない!!!!!!!!!!!!!!!!!!!!!!!!

会場で電源を使わず*1に食べ物を温める方法に関しての今回のイノベーションは携帯おかん器だ。これはAsakusa.rbの花見で野外・火気禁止の公園においていかに日本酒を温めるかという議論の中で発見されたもので、実際に花見で役立ったんだけど、そのときに「これは食品も温められるのでは?」と思い付いてからはTokyuまでは黙ってたｗ
さすがに直接的な火力がそこまでないのでどう使うかな、という方向からそれに向く料理として焼売を選択したのが実際のところで、あとは冷凍庫に大量にあった鶏肉を見て鶏肉焼売にすることにした、という感じ。おいしくできてよかったよかった。

ほかに豚しゃぶ肉が3kgあったのでそのうち2kgを雑に豚しゃぶにした。冷凍庫が空いて助かりました。
あと手羽先は当日朝に存在に冷凍庫内の存在に気付き、これくらいで美味くなるやろ、という感じの適当な調味料といっしょに圧力鍋で煮込んだ。割とおいしくできてて本当によかったよ……。

しゃべった

Maccro Strikes Back from SATOSHI TAGOMORI

まあなんかしゃべりましたね。おわり。

*1:みんな使いはじめると会場の電力供給が保たないから禁じ手

高負荷システムでNVMeデバイス使用時のfstrimとdiscard mount optionの話

先にまとめると

• ディスクI/Oに高い負荷をかけるシステムでNVMeデバイスを使うときweekly cron jobでfstrimが走る状況になってたら停止しろ
• じゃないとfstrimが走った瞬間にI/Oパフォーマンスが刺さって死ぬ
• fstrimを停止するならdiscard mount optionを有効化しろ、ただしその状態でのI/O性能で問題ないかどうか測っておけ
• discard mount optionを有効化しても大きいファイルの削除には気をつけろ、プチfstrimみたいになるぞ
• 追記されるばかりで大きくなるファイル(そして削除されるファイル)はNVMeじゃないデバイスに置いとけ

高I/Oスループットを期待するシステムでのNVMeとfstrim

社内で小さめのインスタンスを多く並べてトラフィックを捌いてたのを色々要件があって大きめのインスタンスにまとめるようなシステムアップデートをやってたんだけど、ローカルファイルシステムに大量の小さいファイルを書く構造をとって、そこを高I/OパフォーマンスなデバイスつまりNVMeを使うことで全体の性能を上げる、みたいな構成にした。

ベンチマークをとってもだいぶ良い感じだったのであれこれ試してから万全の体制……のつもりで本番投入したところ、見事に刺さった。突然ストレージのI/Oパフォーマンスが劇的に下がって全プロセスがスタックするというトラブルが、しかも複数のAWSリージョンでなぜか同時*1に起きた。初回は混乱したままインスタンス増加や入れ替えなどを行って原因がわからねーなーと思ってたんだけど、どうも見てると毎週同じ曜日の同じ時刻に発生している。なんだこれは。

で、調べてみたらこの時刻は weekly crontab のジョブが実行されるよう /etc/crontab が設定されていて*2、 このタスクのひとつとして /etc/cron.weekly/fstrim というやつがあって、これが実行開始されたあとストレージI/Oのパフォーマンスが劇的に悪化するという現象が確認できた。

fstrimがなんなのか大雑把に言うと、SSDやNVMeはデバイス側で使用中のブロックを管理しているが、ファイルシステムは普通ファイル削除時にはファイルシステムのメタデータを削除するだけなので、デバイス側の使用中ブロック情報との間で齟齬が生まれる。fstrimコマンドはこれを解消するために、使用しなくなったブロックをデバイスに通知するためのTRIM命令をまとめて発行するコマンドだ、と自分は理解している。あとは他の解説とかを読んでくれ。例えばAWSのドキュメント "インスタンスストアボリュームの TRIM のサポート"にもこのあたりのことが書いてあって、fstrimを当たり前に使え、となっている。 で、I/O負荷がそう高くない普通の*3システムであれば、ヒマなときにやっとけばいいだろうということで、日曜早朝*4に実行するというcron jobの設定が行われていたのだった。

しかし自分の手元のこのシステムにおいては、ものすごい勢いでファイルを作っては削除してを繰り返す。そのパフォーマンスを担保するためにNVMeデバイスを使ってるんだから当然とも言える。そして大量にファイルが削除されているということはTRIMされるブロックもものすごい量に及ぶため、fstrimを実行した瞬間に大量のTRIMオペレーションが実行されて該当デバイスおよびファイルシステムのI/Oレイテンシが激増、システム全体が死亡するという状況になっていた。 ステージングなどの環境で気付けなかったのは、fstrimによるパフォーマンスの低下はブロックデバイスへの書き込み量に顕著に依存する、ということによる。本番環境のようなトラフィックが無い環境ではfstrimによる影響が軽微な範囲で収まってしまい、気付くのが困難だったためだ。

fstrimが走った瞬間にloadavgが激増して死亡の図

ということで、ファイルシステムでの高スループットI/Oを期待したシステムでfstrimが起動し、その瞬間I/Oパフォーマンスが劇的に低下して無事死亡することになっていた。これ、普通に他所でも起きるんじゃないのかなあ。AWSでNVMeのあるインスタンス使う人って高いI/O性能を期待する人が多いんだろうから、ドキュメントがfstrim実行しろってのは大丈夫なのかと思うけど。

discard mount optionの有効化と次なるI/O性能低下

ところでfstrimについて調べると出てくるドキュメントにはdiscardというmount optionについての記述が出てくる。これはファイルを削除したときにすぐにTRIMオペレーションをブロックデバイスに対して発行するためのもので、当然だがデバイスへの命令が増えるということは、全体のI/Oスループットはいくらか下がる。このためか、例えばRHEL8のドキュメントなどを見ると、避けられない場合を除いてはfstrimによるバッチ処理を推奨している……が、正直これもどうなんだと思う。 一般的にコンピュータシステムの性能をコントロールしやすいのは、時々やってくる高負荷のスパイクよりも、圧倒的に、普段の平均的に少し低い性能のほうだ。予測もコントロールもしやすい。しかもfstrimによる負荷はどのくらいファイルが削除されたか、という極めて変動しやすい要素に依存しているため、事前に予期するのは不可能といっていいと思うんだけど。

ということで、普通にNVMeデバイスを使用するシステムを運用するなら、discard mount optionは有効にするべきだと思う。ので、してみた。もちろんdiscard mount optionによるI/Oスループットの低下には注意する必要がある。各種メトリクスを監視しつつ、本番トラフィックからいつでも外せるようにして注意深くやってみた。 が、また変なことが起きた。全体の性能は問題ないものの、今度は毎時で小さいスパイクが発生するようになってしまった。fstrimによるほど致命的ではないが、本番トラフィックに晒しておくにはちょっとマズい感じのやつ。

毎時loadavgがちょっと上がるの図

毎時nginxのwaiting queueがちょっと伸びるの図(別時間)

これがなんなのかと悩んでみたんだけど、発生時間を手がかりに調べてたら、わかった。crontabによるhourly cronの起動時刻で、何が起きていたかというとlogrotateだった。いやー、まさかねー、って感じだったよ。

discard有効ボリュームにおけるアクセスログのrotate

まさか現代のマシンでlogrotateの負荷が問題になるか? と思ってしばらく自分も混乱していた。はるかな大昔はサーバのCPUコア数も少なく、その少ないコアがlogrotate時のgzip圧縮で持っていかれて全体のパフォーマンスが低下する、みたいなことを経験したことがある。そんなことが現代でまた起きるか? みたいな感じ。

まさか現代のマシンにおいてlogrotateの負荷を気にする日がまた来ようとは

— tagomoris (@tagomoris) June 7, 2019

実情として、このサーバ(で動いてるnginx)が処理してるトラフィックはそれなりにあるので、アクセスログについてはローカルストレージでの保存期間はとらず、hourlyでlogrotateにかけ、また保存世代数はゼロにしてある*5。これでも毎時40GBくらいの量にはなっている。

で、logrotateがこのアクセスログをrotateするということは、つまり、40GBぶんのブロックに対して一気にTRIMを実行する、ということだったのです。discard mount optionが有効の場合は。これに気付いたときは割とがっくりきた。discard mount optionを有効化することでBatch TRIMから逃げられたと思っていたのに、アクセスログのせいでMicro Batch TRIMとでも言うべきものが起きていたのだった。 これが即座に原因だと断定できなかったんだけど、その理由はファイル削除のタイミングとI/Oパフォーマンスの低下のタイミングが微妙にズレることがあるせいだった。これはTRIMオペレーションが実際に実行されるのは非同期化されており、ファイルの削除から少しのタイムラグがあるケースがあるためのようだった。

さてこれが分かれば結論は簡単で、アクセスログをNVMeじゃないデバイスに置いてやればいい。TRIMオペレーションが必要なければこの問題は起きない。問題のインスタンスにアクセスログ用の領域を確保したEBSボリュームをアタッチして、そこにログを書くよう変更してやった。解決!*6

まとめ

NVMeデバイスは高I/Oスループットを発揮できて便利だが、安定したスループットを期待したいのならdiscard mount optionを有効にして運用しよう。またそのデバイス上での巨大なファイルの削除は避けるべきで、そのような例としてはアクセスログなどがある。気をつけよう。

*1:日曜午後3時45分過ぎ

*2:なお全インスタンスのタイムゾーンはUTCにセットされているため、使用中の全リージョンで同一のタイミングでこのジョブが実行されていた

*3:サーバ用途でない

*4:日本時間で15:47はサーバのローカルタイム(UTC)で6:47である

*5:余談だが、このログはFluentdで即座に読み出して外に転送・保存しているので、この運用で良いのです

*6:なお選択肢としては、NVMeデバイスにアクセスログを書きつつもっと頻繁にlogrotateする、という手もなくはない。しかし結局負荷のスパイクの深刻さがファイルサイズに影響されるという状況は変わっておらず、将来的にアクセスログの成長速度がさらに増加したときにトラブルを起こすという潜在的な危険を抱えたままになるので、自分としてはその手段は避けたほうがよいと思う。

RubyKaigi 2019いってきた＆LTやってきた

はい、今年のRubyKaigi 2019は福岡でしたね!

rubykaigi.org

私事でばたばたしてたんだけど、ずっと前から参加を予定してたものだしで、行ってきた。今回もいいカンファレンスだったし、福岡はいい街だしで、よかったですね!

LTやってきた

元々メイントークでproposal出してたんだけど落ちちゃって、LTに出したら通った、のでやってきた。時間がなかったので細かい説明をちゃんとやるより、インパクトとネタ重視で。

Invitation to the dark side of Ruby from SATOSHI TAGOMORI

内容はRuby 2.6で追加された RubyVM::AbstractSyntaxTree を使ってマクロを実現するぜ! というやつ。コードはこちら。

github.com

これ自体はもうちょっと機能追加とか機能修正したりしてから別途エントリを書くつもり。GW後かなー。あとActiveRecordのプラグインとして一部機能を切り出したりしたほうが多くの人にはわかりやすいかもなあ、とも思っている。これは誰かに相談してみたい。
とはいえそれなりに使えるプロダクトを作ったと思っている。着眼点はそんなに悪くない気がするのでもうちょっとプロダクトとしてのアピールを別途してみたい。

LTとしては……こういうLTってだいぶ久し振りにやった気がするけど、当初時間がまったく足りないと思われていた割にちゃんと時間内に最後までしゃべれたし、ウケを狙ったところではちゃんと取れたし、よかったよかった。

そのほかカンファレンス

今年はとにかくパターンマッチがアツい! あと継続してJITと型とGit移行と……あれやこれや。
あと RubyVM::AbstractSyntaxTree には何人もの人が目をつけてて、あちこちでコード解析や書き換えみたいな話があった模様。自分が聞いてた @joker1007 さんのトークとかもやってることの共通点がめちゃくちゃ多くて一人でウケてた。

クロージングで言ってたことだけど、とにかく "We Code" に尽きるな、と思っている。また面白い/興味深いコードが書けたら、次回のRubyKaigiでもなんか話したい。

そのほか福岡など

今年はとにかくPartyがなんか色々とおかしくて、前日はESMのPre Partyでナイトクルージング。船。イベント感がすごい。

1日目のOfficial Partyは商店街の貸し切り……とはいえ通常営業の店もあったりで普通の歩行者なんかも混ざっててマジでカオス。クレイジーという言葉がぴったりだった。すごかった……。スタンディングで日本酒飲みながらダラダラしてた。

3日目はArm Treasure Data主催のAfter Party。テラスから外が開けてていい会場でしたね! ここはいろいろ見回ったり受付やってる時間もあったりで、個人的にはちょっとお仕事モードだった。まあ、まあ。今年も @tanaka_akr さんが「テンションが上がってきたのでスライド作った」というからゲリラテックトークをやってもらったのはすごくよかった。@a_matsudaさんに「録画しといてください」と事前に言われてましたがすっかり忘れてました。

RubyKaigi 2019 After Party で「autoloadの話」という発表をした。https://t.co/IShb0nzCPB#rubykaigi

— Tanaka Akira (@tanaka_akr) April 20, 2019

あとはもつ鍋食べたり水炊き食べたりお寿司食べたり。いやー、いい福岡だった。また行きたい。

まとめ

来年は松本でお会いしましょう。

TDのパーカー等をずらっと並べてみる

自分の勤務先であるところのTreasure Dataは昨年めでたく買収されてArm Treasure Dataとなったが、最近ちょっと必要に迫られてタンスなどを整理しているところ大量にTDパーカー等が出てきてちょっと馬鹿にならない量になった。まあ処分するしかないものの割とレアなやつも混ざっててこのまま闇に葬るのもアレだったので、ちょっとずらっと並べたので記録しとく。

歴代パーカー

知っている限りで最初のTDパーカー。前面がFluentdで背面がTDというのがなんか会社の成り立ちを表してるみたいでけっこう好き。この頃はTD社員じゃなかったのになんで持ってるかというと、最初のFluentd meetupでしゃべったときにスピーカーとしてもらったんじゃなかったかなー。この頃は数も作ってなかったと思うので、今となってはかなりレア度高いはず。CEOの芳川さん*1がいまだにMountain Viewのオフィスでよく着てる。

最初のTDロゴがメインの(おそらく)ゆいいつのパーカー。これ、生地もゴワゴワだしジッパーもないしデザインもいまいちで、誰も着てるの見たことがない。自分もほとんど着たことがない新品同様のはず。同じくTD社員じゃない頃にもらったんだけどなんでもらったんだかもう完全に覚えてない。社員も誰も着てないもんだから見付けたときに思わずこんなんあったなーとか声が出た。レア……かな?

なおこのロゴ、Big Dataをやるぞ! というノリが表されたHDDベースのデザインだったんだけど、後に「いまどき誰もHDDなんか知らんだろ」というツッコミにより変更された(らしい)。

自分が入社した2015年あたりのロゴ(3世代目)とデザインのやつ。この紺色に "WE LOVE DATA" のデザインは長く使われて、いくつも細部の違うバリエーションがある。TDユーザーとかにもだいぶ配ってたような気がするので、持ってる人も多いかも。これは東京オフィス側で作ったんだけど、よく配られてるノベルティのパーカーに較べて生地が断然良くて、嬉しがって使ってた覚えがある。持ってるやつもだいぶ古びてる。

なおこの前に2世代目のロゴがあったんだけど、パーカーは作られてないような気がする。ロゴがなあ……*2。

その次、2017年くらい? のやつ。これも生地がいい。あまりバリエーションは無いのと、これもユーザー企業やTD関連勉強会のスピーカーとかに配ってた気がする。これはいまだに外部の人達が着てるのを見ることがある。

たぶん去年(2018)のはじめとかに作ったやつ。あまり印象がない……のは、割とすぐあれこれ会社的には変わる話があったからかな。ロゴがこの時点で最新のもの(4世代目)になっている。数はけっこう作ったのかなあ。もしかしたらレア度高いのかも。

Arm Treasure Dataになって初めて作られたやつ。USオフィスで一回だけ作られたので最近のだけどかなりレア。日本では超レアかも。目にしたことがあったらラッキー。

はい、日本での現行 Arm Treasure Data パーカーです。あちこちのイベントとかでこれを着た人を見掛けたらぼくたちとあくしゅ!

Tシャツなど

Tシャツはかなりのバリエーションが作られてたはずだけど、いろいろ雑に扱ったりでまともに手元に残ってるのが少ない。手元にあったのをざっと。

このロゴが2世代目のやつ。だいぶレア。なんかイマイチなデザインなのと、3世代目に変わった直後に放映された下町ロケットの帝国重工のロゴがこれに激似だと社員の間でちょっと話題になった。背中のサービス説明が Big Data as a Service だった往時のTreasure Dataを思わせる。

これが3代目ロゴで、単色ピンクなのがポイントで、その色とグレーがコーポレートカラーとして指定されてた。わりと長くこのロゴだったなあ。

Armに買収されたので色がArm色のブルーになったやつと、その後にちゃんと Arm Treasure Data として作ったやつ。右側が最新(現行)のTシャツですね。

おまけ: Fluentd関係

だいぶ昔にごく少数だけ作られたFluentd開発者向け(?)Tシャツ。たぶん10枚とかそれより少ない数しか作られてないんじゃないかなあ。超絶レア*3。Linusのアレをベースにしていることは一目瞭然。

で、後にFluentdの新ロゴ(現行ロゴ)でも作り直された。こっちのほうがもうちょっと枚数があるはず。とはいえレア度高し。

これはCNCFが作ったパーカーで、なんとCNCF Storeで誰でも買える。Tシャツもあるよ。買おう!
写真はないがこのパーカーにTresure Dataロゴが追加されたマイナーバージョン違いが存在して、これはFluentdがCNCFに加わった直後に社員だけに配られたはず。なかなかレア。

まとめ

いかがでしたか?*4 パーカーもロゴもいろいろありましたね!

*1:今ではArmのVP兼GM

*2:Tシャツ参照のこと

*3:だけど@repeatedlyがイベントとかでよく着てるので見たことある人は多そう

*4:これが書きたかった。後悔はしていない。

gradle installDist したときのディレクトリ名と実行ファイル名の設定

ビルドした環境に依存する起動スクリプトを生成してくれるように gradle installDist したとき、ディレクトリ名にはプロジェクトのディレクトリ名が使われる。

my-project$ ./gradlew installDist

# すると以下のツリーができる
# my-project/build/install/my-project/lib
# my-project/build/install/my-project/lib/...
# my-project/build/install/my-project/bin
# my-project/build/install/my-project/bin/my-project (executable)                                                           

普段手元でやる分にはいいんだけど、うっかりcommit hashを使って git repo をチェックアウトしたツリーの下で実行したりすると my-project の部分が全部 commit hash になったりして超めんどくさい気分になったので、これを build.gradle の設定で固定しとけないかと思った次第。

installDistタスクは application プラグインによるものだが、これは Distribution プラグインによってディストリビューションを構成している。また実行ファイルの作成は CreateStartScript プラグインによって行われている……ので、このふたつを調べた。

• https://docs.gradle.org/current/userguide/application_plugin.html
• https://docs.gradle.org/current/userguide/distribution_plugin.html#distribution_plugin
• https://docs.gradle.org/current/dsl/org.gradle.jvm.application.tasks.CreateStartScripts.html#org.gradle.jvm.application.tasks.CreateStartScripts

で、結論としてディレクトリの指定には Distribution プラグインのとこに書いてある baseName をセットすればよく、実行ファイル名の指定は CreateStartScripts プラグインの applicationName をセットすればよい……んだけど CreateStartScripts プラグインのドキュメントに書いてあるとおり application プラグインは暗黙に startScripts タスクをデフォルト設定つきで作成するので、そのタスクの applicationName をセットしなければならない。

結果はこう。

apply plugin: 'application'

distributions {
    main {
        baseName = 'my-own-app'
    }
}

startScripts {
    applicationName = 'awesome-script'
}

これで build/install/my-own-app/bin/awesome-script が常にゲットできる。

なんかちょっとググってみたらそのものの記述がなくて調べるのがめんどかったので書いておく。Gradle 5.0 のドキュメント読んでやってたけど Gradle 4 でも普通に動いた。
あと日本語で上のほうに出てくる Gradle 2.x ベースの日本語ドキュメントサイトは死んでほしい。

RubyConf 2018 に行ってきた＆しゃべってきた

タイトルの通り、と、ついでにシリコンバレー(Mountain View)にある自社オフィスに行ったり、バンクーバーに寄ってリモートで働いている同僚たちと会ってきたりしたので、合計3週間近くの長い北米出張をしてきた。

RubyConf 2018

rubyconf.org

プロポーザルを出したらRubyKaigiトラックで通ったので @joker1007 さんとふたりでしゃべってきた。内容は RubyKaigi 2018 で話した内容のほぼ再演*1なんだけど、もちろん英語で。

RubyConf 2018に登壇するためにL.Aまで行ってきた - joker1007’s diary

前に RubyConf 2014に行ったとき は、正直に言ってトークがぜんぜんダメダメ*2で、それに較べればだいぶマシに英語でプレゼンできるようになったとは思う。当たり前だけどその後に体験した場数が違いすぎるからというのもあるけど。内容が二人で協力した自身のものということもあって、成功と言ってよかったと思う。良かった。 @joker1007 さん、いっしょにやれてよかったです、ありがとう!

Hijacking Ruby Syntax in Ruby (RubyConf 2018) from SATOSHI TAGOMORI

内容はいつもの通り、メタプログラミングであれこれ遊ぶぞ! ということで TracePoint や Binding や method hooks やらを使い倒す内容。
トーク直後に Ryan Davis (@the_zenspider)*3 から "You're terrible!" という非常に欲しかった反応をもらって、直接話しにも来てくれて、本当によかった。RubyConf でもこういうtechieなトークで聴衆を楽しませることはできる。できた。その後でもトーク聞いてたら「あのメタプログラミングのトークやった人?」って話しかけてもらったり、Twitterにもちょいちょい "crazy" と言及されてたりして、良かったなあ、という。「TracePointもBindingもmethod hookも単体では知っていたけど、ああいう風に組み合わせれば実際に使えるんだなと初めて知った」という反応もあったりして、これはもしかしたら世界に禁断の知識をバラ撒いてしまったかもしれんが、いやあ、いいんじゃないですかね。

RubyConf自体は4年前に来たときとあまり変わらず、soft talk *4が多いなー、という感じで、自分のトークが最終日だったこともあってあまり熱心にはセッションに参加せず、ふらふらしたりしてた。参加者の人とちょっと話したりすると割と技術の話が聞きたいよねーと言う人も多いので、もうちょっとそういうカンファレンスになってくれないかなとは思う。
今回は参加者*5に日本人の知り合いもけっこういたので、あまり英語でーとか考えずに知り合いとツルんでビールとか飲んでた。LAは初めてだったけどUS自体はもうけっこう慣れてきたので、その場その場でふらふら。

特にカンファレンス会場のすぐ近くに Karl Strauss Brewing Co. の店舗があるのを到着した直後に発見してしまい、ここで飲む店舗内で醸造されたビールがじつにうまくて通いまくってた。具体的にはLA滞在7日のうちに8回行った。最高*6。だってお昼に行ったら「いまそこで新しくできたビールなんだけど」って試飲を勧められて(おいしかった)、その夜にもう一度行ったらメニューに更にもうひとつ新作が追加されてるんだぜー? 南カリフォルニアに行く予定がある人はぜひ行ってみてほしい。

食事はとにかく肉。あとハンバーガー。USだとまじでこの選択が正義なので、連日外さずに食べてた。

肉だとカリフォルニアワインと組み合わせるのが正義で、行ったステーキハウスでオススメされたHALL St. Helenaのワインがじつによかった。日本で買えないかなあ。肉も、うっかり頼むとちょっと量が多過ぎることを除けば、じつにおいしかった。あとマッシュポテトは飲み物。

LAが発祥と言っていいっぽいカリフォルニアロールも、一度試したけどイマイチだった……んだけど、カンファレンスホテルのすぐそばにあったアメリカングリルの店を試してみたら美味しいやつが出てきたので最終的には成功。いい体験でした。

観光とか出張とか

Mountain Viewに行ってたけどあの地に観光ポイントなどほぼ皆無*7なのはよく知られた事実なので、週末の片方はSan Franciscoに遊びにいって知り合いとお昼を一緒にしてもらったあと、市内をふらふらしたりSF MoMAでよくわからないものを観たり、ビールを飲んだりしてた。

サンフランシスコの空が青くないのは山火事で流れてきてた煙のせい。こうして見ると本当に白いなあ。ひどい。街中はだいぶ煙くさかった。

日本でもニュースになってたみたいだけど、このときカリフォルニアは山火事がひどくて、San JoseからLAまでのフライトでちょうどLA北西で起きてた山火事の上空を通ったので、窓からその様子が見えていた。もう想像を絶する広範囲が黒く焼けていて、火事だとは信じがたい状況だった。こういう体験は日本にいるとできないなあ、とは思う。あとLAからバンクーバーに行く途中で日本人も大好き Mt. レーニア を見たり。おお、カッコいい山じゃん。

LA行くのは初めてだったので、カンファレンス後に3日オフをとってあった。1日目はAsakusa.rbなメンツでロングビーチに行って戦艦アイオワ観光。

もう戦艦、とにかくデカくてカッコいいというか。サンディエゴで観た空母ミッドウェーもそうだけど、これは日本で見られない。実に良かった。

あとはその周辺で、最近USに増えている電動キックボードサービスのLimeを試したりしつつ移動したり。写真はLimeを楽しむ某社CTO。個人的には直進安定性が悪過ぎるあんな乗り物であんなスピードを出すのは怖過ぎた。
あとロングビーチの反対側にある昔の豪華客船クィーン・メアリーも眺めてまわった。とにかくデカいよなー。

2日目はLAの南側にある公園の博物館に、スペースシャトル・エンデバーを観に @kakutani さんと。これも日本には無い……というかアメリカにしか無いやつ。じつに良かった。またしてもデカい。

博物館は主にNASAのものを中心にしつつ、自然科学一般も扱っているものだった。とにかくそこらじゅうに人工衛星だの飛行機だの戦闘機だのが置いてある。ブラックバードとかが野外に無造作に展示されててえええええってなったり、屋内に戦闘機やら飛行機やらが吊るされててどういうこっちゃってなったりした*8。実によかった。

3日目は一人だったので、まずハリウッド方面に行ってLA LA LANDで有名スポットになったグリフィス天文台に。人がめっちゃいた。あとどこまで眺めても陸地で、ちょっとよくわからない……みたいな景色になってる。遊歩道があったのでそのまま降りていってハリウッド中心部まで散歩。

その後はLAダウンタウンまで戻って、他のブルワリー巡りをやってた。リトルトーキョーの近くに集まってる場所があって、そこを4軒ハシゴ……したものの、うーん、Karl Straussがやっぱり一番美味しかったなーってことで、晩御飯はまたKarl Straussで食べてた。しかし街をあちこち歩きまわるのが好きで、今回は色々なものを見た。満足。

で、あとはバンクーバーに移動してあれこれ。カナダは初めてだったけど、バンクーバーは話に聞いていたとおりの綺麗で安全で住みやすそうな街だった。ダウンタウンは思ってたよりも都会という感じ。あと単位がメートル法で摂氏温度なのが最高です。この街でもこの数年でブルワリーがすごく増えたらしく、同僚にあちこち連れていってもらってた。
しかしこの時期はやっぱり寒くて夜が早い。滞在日数も少なかったのもあって、あんまりふらふら見て回るというのはできなかった。また春か夏に来る機会がありそうなのでそのときかな。

あとはいろいろ飲み食いしたものの写真があるので貼り付けておく。みんなも出張にいったらおいしいもの食べておいしいもの飲もうな!

*1:細部をアップデートしたり小ネタをUSに合わせたりはした

*2:ほぼ初体験だったjet lagの影響とか、あれこれ原因はあったんだけども

*3:有名人だ!

*4:どちらかというと技術面中心ではない内容のトークのこと

*5:というか登壇者

*6:ちゃんと調べてみたら近年のサンディエゴで始まったアメリカのクラフトビール流行における本物の始祖のブルワリーらしかった。我々が吸い寄せられたのは必然だったと言える

*7:唯一例外のスポットが Computer History Musium なんだけど

*8:シアトルのボーイングの航空博物館もそうだったけど、なんであんなデカい飛行機を屋内に吊るすんだろうな……

Webアプリケーションのベンチマークをとるときに気をつけている10のこと

10もないかも、と思いながら項目を書き出してみたら10以上余裕であってキリがないので10で収めた。いやあ、あるなあ。

仕事柄よくベンチマークを実行したりしてて色々と思うところが溜まっていたところ、以下のような記事を見掛けたのでなんか書こうと思った。ところでこの記事はベンチマークを実行するための準備作業がループを回して2時間かかるところの待ち時間に書かれている。

sfujiwara.hatenablog.com

ISUCONといえば多少縁があるコンテストで、文中でISUCON5のことについても言及されているので、それも含めて。
自分が業務でいじっているのは "Webアプリケーション" というとちょっと違うんじゃないのというものばかりだが、いやー、最近なんでもHTTPで外部APIを作るからベンチマークのコツとしては大体変わんなかったりするよね。

なおこの記事でベンチマークはどのようなものかとか、どう作るのかとか、そういう基礎的なことについては言及しない。
またベンチマークの対象となるシステムはいわゆるWebアプリケーション、HTTPでリクエストを送りレスポンスを返すシステムで、かつ1リクエストの処理時間は通常1秒未満と期待され、そのようなリクエストを並列でできるだけ大量に処理するシステムであり、計測するのはスループット(req/sec)、並列性、レイテンシ(sec/req)などであるとする。*1

1. 走行中に動的に負荷を変えない

ベンチマークを実行するとき、事前に設定した走行時間(1分なり5分なり10分なり)がある場合、その中で負荷を変えるようなことをしてはいけない。具体的にはベンチマークツールの並列度などを動的に変更するようなことはしてはいけない*2。

システムの性能というのは一瞬だけ走らせて確定するものではなく、ある程度の走行時間を必要とする。その中で全体の結果をサマリしてシステムの性能というものは推定されるのであって、一瞬だけのピーク性能は基本的にはほとんど参考にならない。このため、まずある程度の走行時間を確保する必要がある。
その中で動的に負荷を変えるようなことをすると、ベンチマーク走行のタイムラインにおいて、いつどの程度の負荷だったのかということが極めてわかりにくくなり、システムがいつどのような状況でどのような性能を発揮していたのかが確定できなくなってしまう。性能を明らかにするためのベンチマークにおいて、これは実行の意義を自ら捨てるといっても過言ではない行為である。

もちろんシステムのウォームアップ時などを考慮して走行初期に少しずつ負荷を増やしていくといった意図的な負荷の変更は考えられる。6時間の走行において1/3ずつ異なる負荷で走行させる、などのスケジューリングもありうるだろう。こういった負荷の変更は「静的に」「意図的に」行い、また結果からこの期間を容易に除外して考えられるようにすることが重要だ。

負荷の動的な変更は意図せずして発生することもある。例えば測定対象のアプリケーションが500 (Internal Server Error)を返したときなどに、ベンチマークツールがそれを意図しておらず内部的に例外を起こし、該当スレッドが停止することで並列度が下がってしまう、などの状況などはよく起きてしまう。ベンチマークだからといってクライアントコードを適当に書いているとドツボにはまる。

2. 各走行におけるベンチ対象・ベンチツールのパラメータおよびメトリクスを全部保存しておく

ベンチマークにあたっては、後に述べるように様々な要素を変更しつつ数え切れない回数を実行することになる。このため後から総合的に結果を見るときに必要なのが、いつどのようなパラメータでベンチマークを実行し、どのような結果になったのかを全て明確に参照できるようにしておくことだ。これを忘れると、いつ何を実行したかが簡単に分からなくなり、過去のベンチマーク実行のための膨大な時間が闇に消える。

ベンチマークを行うにあたっては管理しておく要素が極めて多数存在する。代表的には以下のようなものがある。

• 対象アプリケーションコードのバージョン
• 対象システムのインスタンスタイプ
• 対象システムのノード数
• 対象システムの起動時パラメータ
• ベンチマークノードのインスタンスタイプ
• ベンチマークノードのノード数
• ベンチマークツールの起動時パラメータ

「起動時パラメータ」とまとめたが、ここにはもちろん極めて多数のものが入ってくる。代表的には対象システム・ベンチマークツールそれぞれにおいて並列性(起動プロセス数やスレッド数など)があるだろう。他にも割り当てメモリ容量上限、バッファのメモリ・ディスク、各種キャッシュの使用可否、などなどなどなど。送信するリクエストの内容(GET/POST/PUTメソッド、ペイロードのフォーマット、圧縮の有無……)なども変更の対象になる可能性がある。

最初はこんなパラメータ変更しないと思っていても、様々なベンチマークパラメータを考慮した結果、最終的に変更して試してみる、といったことも非常によく起きる。その後で過去のベンチマーク結果を眺めて「このときこのパラメータの値はなんだっけ?」となってしまうケースも容易に起きる。このため変更の可能性は無いと思っているパラメータについても、細大漏らさず記録しておくことが肝要である。

3. ベンチノードのクライアント・インスタンスのリソース使用状況と並列性に気をつかう

ベンチマークを実行するとき、ベンチマーク対象システムのメトリクス(リソース使用状況)には多くの人が気を遣うだろう。しかしうっかりするとベンチマークツール側のメトリクスには注意を払うのを忘れるといったことが起きてしまう。リクエストを受ける側はまだまだ性能に余裕があるのに、ベンチマークツール側がいっぱいいっぱいになってしまってベンチマークスコアが全く上がらなくなり、しかし実行している人は原因に気付けない、という状況もしばしば発生してしまう。
こういったことが起きないよう、ベンチマークツール側のノードのメトリクスにも常に注意を払おう。基本的には各インスタンスのCPUかネットワーク帯域を使い切る近くになるまで*3、1ノード内における並列度を上げるのが望ましい。その上でベンチマークノードのインスタンス数を、並列度の合計が望ましい値になるまで増やしていく。

ただし、HTTPコネクションの並列度がベンチマークのパラメータになるケースもある。この場合には1インスタンスにおけるリソースの使用状況にかかわらず並列度の調整が最優先になる……など、例外ケースはいくつかある。頑張って考えること。

4. 1セットのベンチマークはパラメータ1軸のみを変更しつつ何度もとる

ベンチマークは、基本的に、あるパラメータひとつのみを変更しながら実行する。そのパラメータに対してどのように性能が変化するかを確認するためには、他のパラメータはすべて固定しておかなければならない*4。性能に影響を与えうる複数のパラメータを同時に変更することは絶対にしてはいけない。ベンチマークの意味がなくなってしまう。

これは当たり前のようにも思えることだが、実際にベンチマークを実行していると意外にやってしまうことが多い。どんなに退屈だろうと、あるいは複数の変更が独立していることが自明に見えても、複数のパラメータの同時変更は鬼門だ。本当に思わぬところで影響が出たりするし、最終的に結果を考察する上でノイズになったりもする。

5. 1セットの結果から仮定を立て、次セットは別のパラメータ1軸を対象に実行する

ベンチマークにより性能計測を行いたいという場合、性能に影響するパラメータがひとつだけということはあまり無いと思う。ある1セットのベンチマークでパラメータAについてベストな設定がわかったら、次はパラメータAをその値に固定した上で別のパラメータBを軸として設定を変更しつつ別のベンチマーク走行セットを実行する。

これによりパラメータBの最適値が分かったとするが、このとき即座に次のパラメータCに行ってはいけない。パラメータBの最適値が当初の値と異なる場合、それがパラメータAの最適値に影響を与えないとは限らないからだ。ということで今度はパラメータBを発見した最適値に固定し、一度パラメータAに戻って再度ベンチマークを実行する。パラメータBの変更がパラメータAに影響を与えていなければ前と同じ最適値が得られるはず。影響を与えていれば異なる最適値が得られる……ので、その値を使って再度パラメータBに戻りベンチマークをまたまた実行する必要がある。

このようにしてA, Bそれぞれについて完了したら、ようやくパラメータCに移ることができる……。

6. 納得するまで繰り返す、走行時間も変えてみる

ということで、様々なパラメータについてあれこれ変更しつつ、納得するまで試行錯誤を繰り返すことになる。長く根気の必要な作業である。

またこのとき、ある程度結果が見えてきたらベンチマークの走行時間についても気にかけてみるとよい。短時間であれば良い性能を示しても、同じ負荷で長時間走行させるとある時点で突然性能が劣化する、ということもよくある。そのような性能特性では当然本番のトラフィックに投入するとトラブルを引き起こすので、事前に見付けておく必要がある。

7. 計測する性能における期待値と最大値は明確に分けて考える

ベンチマークにおいて計測する性能とは、実際にはいくつもの数値によって総合的に構成される。典型的には処理の並列度(同時コネクション数)、処理時間(sec/req)そしてスループット(req/sec)だろう。また並列度やスループットは時間平均*5の推移をとればよいとしても、処理時間については平均値とともに各パーセンタイル値(50, 90, 95, 98, 99 など)を取るべきだ。

さてこういった性能指標をどう扱うか。システムのこれら全ての性能指標について最大値(最良値)を追求する、というのは実際には不可能といってよい。検証すべきパラメータは膨大なので、おそらくいくら時間があっても足りない。こういったときはベンチマーク全体の設計として、いくつかの性能指標は「この程度の性能を期待する」という値を設けておき、それが満たされてさえいるなら最大値は追求しない、という進め方をするほうが良いだろう。
そのシステムの実際のワークロードを考えたとき、例えば並列度はどう考えても10,000を超えない、というようなケースは多いはずである。またスループットは 1,000 req/sec 程度あればよいが処理時間は 100ms/req を切っている必要がある、などの要求の場合、最大スループットを計測することにはほとんど意味がない。ターゲットのスループット*6が問題なく処理できることを確認したら、あとは問題となる処理時間のメトリクスに集中して更なるベンチマークを実行するほうがよい。

8. 走行中の負荷はできるかぎり平準化する

ベンチマークツールの出来によるが、あまり適当にやると時間あたりに送るリクエスト数がひどく上下してしまう、というようなことが起きる。ある瞬間は500req/sec送っていたのが、次の瞬間には300req/secになってしまう、というように。これは測定対象の瞬間性能の上下*7に引きずられてリクエスト送出側の送信数も素直に上下する、という現象と区別がつきにくいが、区別するべきだ。
現実のワークロードはシステムの性能にあわせてリクエスト送信数を上下してくれることなどほとんど無い*8。このため可能なら、ベンチマークツールはベンチマーク対象の性能にかかわらず一定のスループットでリクエストを送信しつづけることができる構造のものを使用する*9べきだ。またその送出リクエスト数(負荷)は不用意に上下しないものがよい。

こういったベンチマークツールを作るのはわりと難しく、世の中にある単純なもの*10はこの機能をもっていないものも多い。
やむをえずこの機能のないベンチマークツールで負荷をかける場合は、測定対象のレスポンスタイム(sec/req)に注目するとよい。対象システムの性能上下によってスループットの上下が発生する場合、かならずレスポンスタイムの悪化*11が裏で起きるため、それをメトリクスで確認できるはずだ。

またこのような問題は、送出するリクエストの組み立てを事前にまとめて行う、といった構造のベンチマークツールを書いたときにも起きやすい。以下のようにして起きる。

リクエストを1,000,000件組み立て(無負荷) → 組み立てたリクエストを順次送出(負荷走行) → またリクエストを1,000,000件組み立て(無負荷) → ……

リクエストを事前に組み立てるのは負荷走行中のリクエスト送出毎のディレイを短くするためには有効だが、組み立てたリクエストを全て送出し切る前に完了する類のベンチマーク走行でしか使うべきではない。実際にベンチマークを実行する場合には数時間といったスパンの長時間走行も考えるべきだから、現実的には全てのベンチマークにおいて、あまり適切ではないといえる。
ベンチマークにおいては、全てのリクエストは送出ごとに組み立てから行うほうが負荷の平準化のためには良い。ベンチマークノード1ノードが送出できるリクエストのスループットは多少下がるが、それはノード数(並列数)の増加で補うべきだろう。

9. 異なる種類のリクエストは公平に混ぜて送る

現実のワークロードに近いベンチマークを行おうとすると、おそらくベンチマークツールから送るリクエストは複数の種類のものを混在させることになるだろう。複数のログインユーザを装うことになるかもしれないし、それぞれ異なるリソースを読み書きするリクエストを並列で発行させたい、ということもあるかもしれない。
このようなリクエストを送るときは、可能な限り綺麗に混在させるよう努力するべきだ。例えば時間によってアクセスされるリソースが偏っている場合は必要な情報がメモリキャッシュに乗りきってしまい、実際よりも高いパフォーマンスを示す、などということが起きうる。そのような状況から得た結果は考察を混乱させてしまい、悪影響が大きい。

実際にどう気をつけるかはベンチマークツールなどの実装に大きく依るが、自作する場合、リクエストタイプ毎にリクエストワーカースレッドを作る、などとするとこの偏りが発生しやすい。レスポンスタイムの短いリクエストを担当するスレッドだけが規定のリクエスト数を走行させきってしまい、あとはレスポンスタイムが長いリクエストだけが流れ続ける時間が生まれる、という状況が生まれやすいからだ。ベンチマークツールを自作する場合は、まず全種類のリクエストを綺麗に混ぜ、それを全ワーカースレッドに公平に割り当てるようにすればよい。

10. 結果は複数のスコアから総合的に解釈する

ベンチマークの結果は複数の性能指標を見て総合的に解釈するべきだ。前述したように典型的なWebシステムであれば処理の並列度(同時コネクション数)、処理時間(sec/req)そしてスループット(req/sec)が考慮の対象になるだろう。たとえスループットを最大化することが目的であっても、そのためにレイテンシの95パーセンタイル値が大幅に悪化する、などということになれば現実的には使えないシステムになってしまう。またベンチマーク走行中に性能値が極端に上下するようなものも好ましくない。

CPUやメモリ、ストレージI/Oなどのメトリクスにも注意を払う必要がある。現実的に運用不可能なリソース消費量になっていないか、長時間走行において不自然なCPU・メモリ使用の増加が起きていないか、などはチェックしておくべきだ。

まとまらない

もうかなり書いたのでこのくらいにしようかと思うが、何か大事な項目を書き忘れているような気もする。細かいことを言うとこれ以上にもあれこれ多数あるだろう。「大事なこれを忘れてるだろ!」というのがあったら教えてください。

EX. ISUCONベンチマークの特殊性

発端がISUCONベンチマークの記事だったので、それについても書いておこう。

ISUCONのベンチマークは、通常業務で実施するベンチマークと較べると極めて特殊なものだ。上述したように通常ベンチマークといえばパラメータを変えながら何度も何セットも実行してようやく性能指標の最大値を求める。ところがISUCONのベンチマークはたった数分、一度きりの走行でスコアという名前の性能値を算出しなければならない。
また対象システムの性能は初期状態からコンテスト末期の状態でおよそ100倍の性能差があることも全く珍しくないが、この両方をひとつのベンチマークシナリオでカバーするのは、普通に考えると不可能に近い。

fujiwaraさんのエントリで記述されているので詳細は省くが、ISUCON 3, 4, 6, 7, 8 ではいくつかの方法*12で負荷が調整されるようになっている。これは実質的にはすべて並列度の操作だ。workloadを手動で指定する方法でも自動調節する方法でも様々な問題がある。特に自動調節はfujiwaraさんのエントリの「自動負荷増加の問題」に書かれている通り、本来(通常)のベンチマークからほど遠い思考を要求されることになる。コンテストだからといえば良いかというと、本来の「できるだけ本物の業務に近いことをやる」という主旨に外れること甚しく、個人的にはあまり好きではない。

ISUCON5のベンチマーク*13は何をやったかというと、並列度は固定してあった。走行中に並列度は上下しない。その上でリクエストに関する許容レスポンスタイムを大幅に引き上げ、非常に遅いリクエストであってもベンチマークツールが頑張って待つ、ということで初期状態でもなんとかスコアが出るように調節したように思う。その上でできるだけ高速に動作するベンチマークツールを作ることで、参加者がアプリケーションの高速化を行ってもそれに追随できるスループットが出ることを目指した……はず。
いま確認したら、それでも予選時には上位チームのスループットには追随できずサチったケースがあったらしい。本戦では並列度が高めに設定してあったから問題は出なかったようだ。

つまり実質的に、ISUCON 1, 2, 5 は固定の並列度に対してスループットを上げる(==レスポンスタイムの短縮を狙う)ゲームであり、それに対して他のISUCONは増加する並列度に対して追随することでスループットを上げるゲームである、と言える。
これが明示されていないことをどう思うかは、うーん、どうなんだろうなあ。まあいいのかなー、という気はする。

*1:同僚が詳しいのですが、たとえばRDBMSのベンチマークなどを実行する場合、共通する考え方はあるにせよ細部は大きく異なります

*2:もちろんこれは、だんだん負荷が上昇するようなケースで起きる問題を特定したい、というようなケースでは当然守られない。が、それはおそらくデバッグのためのケース再現であってベンチマークではない。

*3:本当に使いきってしまうとコントロールなどに色々弊害が出るので、いくらか下に上限を設けること

*4:もちろん実質的に複数のパラメータがセットになっているものはあわせて変更する必要があるが

*5:短時間、たとえば1秒や10秒ごとの平均値

*6:の、安全を見てさらにある程度上のスループット

*7:レスポンスタイムの上下といった形で現れることが多い

*8:例外ケースとして、現実のワークロードにおけるリクエスト送信側がキュー＆ワーカー構造になっていれば性能の上下に対して敏感にならず、平均のスループットだけを相手にすることができる

*9:あるいは自分でそのように作る

*10:abなど

*11:あるいは処理並列度の低下だが、処理並列度はベンチマークツール側で固定できることが多いので、実際には並列度の上下が動的に起きることは少ない

*12:workload, 自動調節およびSNSシェア

*13:実際にはISUCON 1, 2も根本は同じだが