日曜日, 11月 22, 2009

【Google App Engine】 TaskQueueはスケールしない！？３ このエントリーを含むはてなブックマーク


TaskQueueを使ってPDFを生成する

　先の記事で疎結合、バージョニング、非同期がスケーラブルにするための要素だと述べた。私たちが提供するReflex iTextサービスでは、PDF生成サービス(図中 pdfservice)やデータサービスなどは、独立したサービスとして立てられる。独立したサービスは（カッコつけていえば）サービスコンポーネントとして考えることができる。サービスコンポーネントは、ServiceとReferenceの2つの口をもち、いわゆる芋ずる式に（疎）結合できる。そして、TaskQueueを利用することで、それらを非同期かつ並列に実行することができる。これを、ぶいてく流サービスコンポーネントアーキテクチャーと呼んでいる。



　例えば、請求書アプリでは、
http://invoice.latest.reflexcontainer.appspot.com/invoice?invoiceNo=DEMO1&xml

でGETすることで、データサービスからデータを取得することができる。(&jsonとすることでjsonも取得も可能）
　そして、以下のようにデータとtemplateを同時に与えることでPDFを生成する。内部的には、pdfservice(service)に与えられたurlを元に参照(reference)を実行している。
http://pdf.latest.reflex-itext.appspot.com/pdfservicegae?template=http://invoice.latest.reflexcontainer.appspot.com/invoice.html&entity=http://invoice.latest.reflexcontainer.appspot.com/invoice?invoiceNo=DEMO1&xml


　さらに、TaskQueueによって起動された複数のTaskからこのリクエストを実行すれば、大量のPDFを瞬時に生成することができる。これは以下のような仕組みになっている。



スケールしない現実

だが、ココや、ココに書いたとおり、実際にはスケールしない。
　700ページを12リクエスト(合計8400ページ)処理させた場合について計測してみると、unit=70の場合(700/70*12=120タスク)で約15分かかってしまう。unit=70の場合で１タスクの処理時間が30秒未満なので、本当に並列処理されているとすれば、30秒で完了しなければならないはずである。ちなみに、unitの数と処理時間の関係は以下のとおりである。unit=50で最速であるが、それでも1分かかっている。

  • 1 : 生成（全タスク完了まで）
  • 2 : 取得（PDFマージ処理からクライアントで文書を開くまで）
    • unit=70,total=700 (タスク件数 : 10件)
      1. 1分20秒,1分10秒
      2. 57秒。42秒
    • unit=60,total=700 (タスク件数 : 12件)
      1. 1分20秒。
      2. 1分。
    • unit=50,total=700 (タスク件数 : 14件)
      1. 1分2秒,1分15秒。
      2. 1分4秒,47秒。
    • unit=40,total=700 (タスク件数 : 18件)
      1. 1分15秒。
      2. 54秒。
    • unit=30,total=700 (タスク件数 : 24件)
      1. 1分20秒,1分35秒,1分14秒。
      2. 50秒,43秒。
    • unit=10,total=700 (タスク件数 : 70件)
      1. 1分52秒,1分33秒。
      2. 52秒,50秒。


詳細分析
  • どれも以下のWarningが多発
    Request was aborted after waiting too long to attempt to service your request. Most likely, this indicates that you have reached your simultaneous active request limit. This is almost always due to excessively high latency in your app. Please see http://code.google.com/appengine/docs/quotas.html for more details.
    TaskQueueのワーカー側から出力されている様子。
    2個目の終了ログの前に上記ログが複数出力されているケースが多い。
    処理の合間にもちらほら出力される。
    Maximum RateとBucket Sizeを下げる（どちらも5に設定）と、abort発生頻度が下がる。
  • 1はインスタンス2個、2,3はインスタンス3個
  • 全ての処理が終了するのは、どれも15分程度で変わらない。
  • あるインスタンスが最初に処理を行う場合、２回目以降と比較して処理時間が長い。
  • 一度に4個程度並行処理を行っている。そのうち3個は同じJVMで、1個だけ別のJVMというパターンが多い。
  • また、クライアントから連続してリクエストを投げた際（今回のテストでは4秒間隔）、エラーが時々発生する。１回目のリクエストは成功し、２回目のリクエストでエラーが発生することが多い。


　ボトルネックがどこにあるかわからなかったため、下図のように、Memcacheにデータを格納することで、ネットワークI/Oをなくすケースについても計ってみた。




  • TaskQueue処理データをMemcacheに登録するテスト

  • 1Taskあたり700ページ作成すると、dispatcherでの処理で以下のエラーが発生してタイムアウトする。240～300ページあたりで、エラーになったり正常終了したりした。
    • jp.reflexworks.pdfservice.PdfDispatcher doGet: com.google.apphosting.api.DeadlineExceededException: This request (789cb38865d5e3d2) started at 2009/10/27 06:10:31.448 UTC and was still executing at 2009/10/27 06:10:59.946 UTC．・・・

  • 8400ページ出力処理（以下、1Taskあたり240ページ作成とする）
    TaskQueueのMaximum Rate : 5.0/s、Bucket Size : 5.0に設定。
    1. unit=20,total=240を35回リクエスト（クライアントからのリクエスト間隔:4秒）
      • タスク数は、12×35=420個。
      • １タスクにつき処理時間が6～11秒かかる。
  • 実行結果
    • dispatcherへの1回目のリクエストはエラーになった。2回目から正常終了。
    • やはり"Request was aborted ..."のWarningが所々出力されている。（4回正常、1回Warningログというパターンが多い）
    • dispatcherの応答時間が長い。
      • Memcacheを使わない場合は2～7秒、今回は9～10秒。
    • １タスクあたりの処理時間は、Memcacheを使わない場合とあまり変わらない。
    • 総処理時間は19分。（エラー分の2回を追加でリクエストした。）
    • VM起動数は4個。
    • リクエストを投げ終わる時間は10分。


    • この結果でわかることは、

    　１）リクエストを投げ終わる時間は10分だが、リクエストを投げてから、すぐにTaskが起動されるため、Task処理開始から終了までにかかる時間は19分である
    　２）1タスクの処理時間に変化がなかったことで、一括検索＋Memcaheに格納のメリットは見い出せなかった
    　３）１回目のリクエストでエラーとなるケースが多い（この件については、次回の記事にて、詳細に分析した結果を報告する）

    ちなみに、TaskQueueを使わないで、すべてdispacheで処理したケース（つまり、多重度１）では、

  • 8400ページ出力処理、クライアントからのリクエスト間隔を0秒にしてテスト
    • リクエストを投げ終わる時間は7分。
    • dispatcherへのリクエストは、35回中2回エラー
    • 総処理時間は19分。（エラー分の2回を追加でリクエストした。）


    • また、MemcacheのI/O回数を減らし、20件分をまとめてgetしたケースでは、

  • Memcacheへのデータ登録単位を1件からunit(20)件にし、Task側ではMemcacheからgetする回数を1回にしてテスト
    （Memcacheに、1個のキーに対しデータunit(20)件分のjson文字列を格納する。）
    • データ登録単位1件の場合と変わりなし。


＜続く＞

＜追記＞
　・　軽いWorkerタスクを別途用意して連続して負荷をかけることでVMは16程度起動することがわかっている。今度はServletContext＋UUIDで負荷分散状況を調べてみた
　・　WdWeaverさんの実験 スケールアウトの真実
POSTED BY takezaki 時刻: 8:58 午後

2 件のコメント:

Unknown さんのコメント...

あのwarningは、リクエスト処理中に後続のリクエストが来てqueueにつまれ10秒以内に処理されなかったときに発生します。

つまり、AppEgnineは30秒ルール以外にも、負荷が集中するときには、10秒以内に処理しないければいけないという10秒ルールも存在するのです。

10秒ルールを守ったとしても完璧にスケールするかはまた別の話ですが、今のAppEngineの能力を最も引き出せるということはいえると思います。

23/11/09 13:10
takezaki さんのコメント...

コメントありがとうございます。次の記事に詳細を載せました。http://blog.virtual-tech.net/2009/11/google-app-engine-taskqueue_23.html

23/11/09 22:17

コメントを投稿

登録: コメントの投稿 (Atom)
 
© 2006-2015 Virtual Technology
当サイトではGoogle Analyticsを使ってウェブサイトのトラフィック情報を収集しています。詳しくは、プライバシーポリシーを参照してください。