appengineのリクエストライフサイクルの推測

今までのテスト結果などからまとめたリクエストライフサイクルを図にすると多分こんな感じ。

ここで、スピンアップを行なう実行単位をスピナープロセスと仮定すると、それらも起動時間がそれなりにかかるかもしれない。

まず、キューと予想されるリクエストの集合から、最初のスピンアップとなったリクエストを抜き出すと、こんな感じになる。このテストは500ms待ちのみのサーブレットで行なったものなので、全て同時に実行していれば1.2秒程度で並んでおかしくないのだけど、4秒、5秒と掛かっている場合がある。

また、スピナープロセスはリクエスト処理で何かブロックされてしまうと、次のスピンアップがブロックされてしまう。これは別のWebハンドラを作っておいて、デプロイ直後のリクエストでURLFetchServiceでそのURLをキックしてみると分かる。別のキューに振られないとインスタンスが起動できずにRequest was abortedされるはず。

処理時間やスピンアップに時間が掛かってると、スケールアウトのプロセスを一部ブロックしているようなものなので、急激なリクエストの増加に対応できないってことになる。

これはある意味AppEngineの弱点かもしれない。

昨日の続き

インスタンスの起動間隔について

キューごとのインスタンスの起動間隔は処理開始時間をみるとちょうど処理時間+spinup時間程度になってるようだ。

昨日の内容のツッコミ

1. higayasuo @WdWeaver 検証のやつですけど、なぜ1つのqueueに関連付けれられているインスタンスがあの5個と特定できているのかがわからない #appengine
2. WdWeaver @higayasuo 最初に投げたリクエストのうち、インスタンスが起動したリクエストの時間より前のリクエストを処理しているものが5つあった、ってことです。
3. WdWeaver @higayasuo で、UUID=b8418f11-f0a4-443e-b4d8-35cad8a2cc3cを境にして、それ以降の起動インスタンスはこの5個のインスタンスが処理した時間帯のリクエストを処理していません
4. WdWeaver @higayasuo んで、キュー共用してればキューの中から拾って処理が可能なんじゃないかなと思ったので、キューの分割単位になってるんじゃないかなーと。マシン単位なのか、ソフトウェア的な分割なのかは分からないですけど。
5. higayasuo @WdWeaver thx. だとするとキューが40というのも説明がつきますね #appengine
6. WdWeaver @higayasuo はい。ただ、昨日追加で実験してみたところ、必ず40というわけでもないようです。

appengineのスケールアウトの結果を吟味した

#ajn3で披露したスケールアウトの様子について、リクエストの到着時刻を元にログを並べ直すと、面白い事実が分かってきた。（ちなみにappcfgでダウンロードするログにはこの到着時刻やcpu時間等が含まれないので非常に分析しづらい。)
テスト方法についても反省点があるので、ここにメモを残そうと思う。

分析に使っている結果シートはこちら
0.5秒待ちで、120件を一気に投げてみた結果はこちら

JMeterの挙動について

設定ミス、私自身もJMeterの設定について不勉強だったため、初期値として60thread,30request/secとして設定したJMeterの挙動が、期待するものとは違った。
まず、すべてのthreadは、スピンアップした直後にリクエストを送信していた。
したがって、60reqeustが当初appengine側に送信されていた。
また、各クライアントスレッドはレスポンス待ちを行うため、次回のリクエストまで1秒以上～10秒前後未満(最大、キューのタイムアウトまで)の待ちが発生する。
以上の状況から、リクエストの間隔が一定のレベルでかかるような状況を作ることができていなかった。
負荷のかかり方が、appengine側のスループットに依存する状況(スケールの状況に依存するってこと・・・)になってしまっているため、平均すると、リクエストは11.3req/sec程度に落ち着いていた。
大体スケールしたインスタンス数(13個)になってるので、ああ、なるほどなと。
テストの系にJMeterの挙動が含まれるような形になってしまっていたのは残念。

ただ、以降に記述するとおり、最初の1秒間に実行された60個のリクエストが興味深い結果を残してくれていた。

リクエストのキューについて

インスタンスを起動したリクエスト時刻以前のリクエストを同一インスタンスで処理するパターンと、起動したリクエスト以降のリクエストのみを処理するパターンが存在していた。
リクエストのキューはおそらく物理的に複数存在し、キューに複数のインスタンスがぶら下がるようになっていると考えられる。（要するにGDDの説明通りの構成ってことかな）
これは物理的な構成を考える根拠になりそうだ。
おそらく物理的に分割されているため、キューが別々になってしまったリクエストはキューをまたがったインスタンスへ移動することはできないのだろう。
ひとつのキューにぶら下がったインスタンスで処理しきれないリクエストがRequest was abortedにつながっているように思える。
具体的にはUUIDがb8418f11-f0a4-443e-b4d8-35cad8a2cc3cのインスタンスで、少なくともキューが
全て共用されていれば、このインスタンスでも起動時刻以前のリクエストを処理していないとおかしい。

リクエストキューの個数について

ひとつのリクエストのキューに対し、40件程度詰め込まれていることが事実としてある(リクエスト時刻を巻き戻って処理しているインスタンスのリクエスト合計がちょうどこれくらい)。実はこれがquotaとリソースの利用状況との関係になるのではないかと予想が立った。
GDDの説明だと、初期状態だと1つのフロントエンドに3つのAppEngineマシンがぶら下がっている構図だ。さて、40*3とは？120だ。ちょうどfreequotaのリクエストの秒間の上限に近い値となる。
もちろん、物理的な振り分け自体はこのようにならないと思うが、利用リソースの計算としてはここを目指した設定値ではないかと考えている。

キューの割り振りについて

1つのIPからのリクエストのテストであったため、多数のIPからアクセスされる状況については分からないが、上記のリクエストキューの個数と時刻をみると、フロントエンドから、単純にリクエスト40件程度ずつラウンドロビンをしているように見える。ただ、この結果を踏まえ、0.5秒待ち、120件のリクエストを一気に投げてみた結果から、キューのサイズは可変で、フロントエンドの負荷分散ももう少し高度なことをやっていそうなことがわかった。

リクエストキューの個数と失敗数の検証

上記から予想している40個というリクエストキューのサイズと、失敗数を検証してみたい。
60件のリクエストのうち、ひとつのキューにぶら下がりスケールしていると思われるインスタンスのUUIDを抜き出し、60件のリクエストのうち、処理できた件数を集計する。
1. 52f48031-6af2-487e-9809-84fb51adde63 .. 10件
2. 988cbe3a-1751-4a09-8faf-67f51f07e6c3 .. 9件
3. b3c1eb76-277b-4e17-b713-ea9d09a875e8 .. 7件
4. eda3152a-8445-478e-876c-1460b5ebd016 .. 5件
5. 514bd79b-1b19-429d-a383-e26382144fdd .. 4件
... 全部で35件。失敗した件数が5件なので、計算は合う。
リクエストとしての処理時間から逆算した処理可能数と比較すると、少し処理した数が多いが、処理時間はフロントエンドとの通信遅延なども入った値と考えるとつじつまあわせはできそうだ。

とりあえず今日はここまで

appengine java night #3で発表してきたよ

「スケールアウトの真実？」
というお題でGoogle App Engine / Java のスケールアウトの動作の考察について発表させていただきました。

appengine java night 3で発表したLT資料はこちらです。
おなじみ？の、ひがさんのツッコミとフォローのおかげで議論が深まってよかったです。
スケーラブルなアプリケーションをAppEngineで構築するヒントになれば幸いです。

実はこういう勉強会でお話をするのは初めてでした。
発表の機会を頂いた皆様、ありがとうございます。
LightningじゃなくてLongだというツッコミごもっともです。
（40分くらい使ってしまったらしい）
後続で発表できなかったかた、ほんとすいませんでした。

自分も議論に混じったりしながらだったので、うまく覚えておけなかったんですが、
ひがさんのトークからいくつかポイントをメモっておきます。
ちょっと記憶があやふやでデタラメ書いてるかもしれないので
ツッコミ推奨です。

AppEngineが1instance/vm である証拠

Runtime#hashCodeが毎回同じなのは多分いつも同じ起動順序をたどっているということ。 Thread idはstaticフィールドで管理されているので同一VM内であればインスタンスのロードが ClassLoaderで分離されているとしても変わらないとおかしい。 VM自体に手を入れているとは考えられないため、ほぼ1instance/vmで間違いない。

実質1Thread/instanceの理由の予想

スレッド使ってしまうと利用リソースの予測が立たなくなる。

リクエストをキューイングしている理由の予想

これも同様に利用リソースの予測が立たないから。ストリーミング(というか、KeepAliveのことかな？) を止めてるのはこのためだと思われる。

TaskQueueがうまくスケールしない理由

あらかじめ継続的なリクエストでインスタンスがあったまってないと 処理が分散されにくいからではないか。@kazunori_279さんのところだと、テストなどでインスタンスがあったまっていたので、うまくTQも分散されていたのかもしれない

初期化の件

appengineではインスタンスの初期化は鬼門。今までのJavaフレームワークの概念では インスタンスの初期化で頑張って（リソースを相当割いて）、アプリの高速化を図っていたが、appengineでは逆の視点が必要⇒専用のフレームワークが必要と考えられる。

参考リンク

http://d.hatena.ne.jp/kazunori_279/20091027/1256642767
http://blog.virtual-tech.net/2009/11/google-app-engine-taskqueue_23.html