applicationごとにspinupの性能が違うかも?という問題

3
ほるっふーdeveloper @pto_developer

VIP ver1.4。twitter除外オプション追加。やっぱりspinup+cronがこける。不可解なのはspinupの処理時間に大きなムラがある事。1500ms~11000msってなんでそんなぶれるん? #appengine

2010-01-10 02:53:23
shin1ogawa @shin1ogawa

@pto_developer 1500msの時もspinupしてるのは確実なんですか?

2010-01-10 02:56:28
ほるっふーdeveloper @pto_developer

@shin1ogawa ごめんなさい、不勉強で質問の意味が良く分かりませんorz spinupはslim3のログ(Initialized FrontController(UUID...)で判断してますが合ってますか?

2010-01-10 02:59:10
shin1ogawa @shin1ogawa

@pto_developer いや、1500msの時はインスタンスがひとつ以上生きていて、spinupしていないんじゃないかな?と思いました。さすがに1500-11000ってのはブレすぎだなーと。

2010-01-10 03:01:28
ほるっふーdeveloper @pto_developer

@shin1ogawa 処理時間はブレまくりですが、cpu時間は1300-1800cpu_msで安定してますね。主たる処理はTaskQueueの投入程度。

2010-01-10 03:08:19
ほるっふーdeveloper @pto_developer

@shin1ogawa spinupの処理時間は(Initialized FrontControllerのログ時刻) - (アクセスログの時刻)で求めてます。この前提が間違ってたらすいません。

2010-01-10 03:14:39
shin1ogawa @shin1ogawa

@pto_developer TQから呼ばれたにしろcronから呼ばれたにしろ、「spinupしたのかどうか?」の判断はどのようにしていますか?

2010-01-10 03:16:47
ほるっふーdeveloper @pto_developer

@shin1ogawa 先ほども書きましたが、slim3のログ(Initialized FrontController(UUID...)で判断してますが合ってますか?spinupの概念自体が間違ってるかもという不安も出てきました・・・

2010-01-10 03:19:59
shin1ogawa @shin1ogawa

@pto_developer ううむ、なるほど…。slim3に到達するまでにそれほど掛かっているのは確かにおかしいですね。 #appengine のプロダクション環境に何か問題が出てるのかもしれんし、自分も稼働させているアプリをチェックしてきます。

2010-01-10 03:25:21
ほるっふーdeveloper @pto_developer

@shin1ogawa そうですか。ずっとこんな感じなので一時的な問題ではないと思っているんですが。ちなみに独自のFilterはありません。

2010-01-10 03:28:27
shin1ogawa @shin1ogawa

@pto_developer なるほど。自分はslim3のfilterは使っていないので参考にならんかもしれませんが、spinupの時間にそんなに差があるアプリはありませんでした。

2010-01-10 03:37:24
shin1ogawa @shin1ogawa

@pto_developer 自分のアプリだと1500-2500ms以内に終わってるのがほとんどなんで、何か別の原因があるんでしょうねぇ…。

2010-01-10 03:39:20
ほるっふーdeveloper @pto_developer

@shin1ogawa そうですか。ご助言ありがとうございました。明日もうちょっと頑張って切り分けをしてみます。 #appengine の問題なのか、#slim3 の問題なのか、アプリの問題なのかきっちりさせなきゃいかんですね。

2010-01-10 03:40:37
shin1ogawa @shin1ogawa

重い処理が走ってる最中に新たなリクエストが一旦キューに入って、その途中でspinupが走り出したって事なのかな。

2010-01-10 03:40:45
shin1ogawa @shin1ogawa

@pto_developer spinupに時間がかかるなーというリクエストの直前に、別の時間がかかる処理が走っていれば、さっき書いた「リクエストキューでしばらく待たされてから別ノードでspinup」っていう動作なのかもしれませんねー。

2010-01-10 03:44:13
ほるっふーdeveloper @pto_developer

@shin1ogawa 例えば直前5分アクセスが無くても、spinupに10秒以上かかって"waiting too long"になることがありますね。ちなみにこの場合はFrontControllerのログは出ず。なんかもう確率的に起こってるような感じです・・・

2010-01-10 03:51:17
ほるっふーdeveloper @pto_developer

@shin1ogawa ちなみに @sho235711 さんも同じようなcron+spinup問題で悩んでるようです。#appengine

2010-01-10 03:55:15
higayasuo @higayasuo

@pto_developer #appengine のcronは何の処理が同時に走っていない時でも、Request was abortedになるときがあります。その時は #slim3 にリクエストも届いていないのでspin upとは無関係です

2010-01-10 09:19:40
higayasuo @higayasuo

#appengine のcronはspin upに関係なくRequest was abortedになる可能性があるって書いたけど、関係はあるっぽい m(_ _)m

2010-01-10 09:33:49
higayasuo @higayasuo

ログを調べるとRequest was abortedになった直後のリクエストでどれもspin upが起きてました。直後と言っても1分後なので同時リクエストの時じゃないんだけど。最近、1分毎にcron走らせて実験しているので #appengine

2010-01-10 09:37:14
higayasuo @higayasuo

1分毎のcronは何もしていないので、cronの処理の重さは関係なさそうです #appengine

2010-01-10 09:38:26
higayasuo @higayasuo

@pto_developer 先程書いたRequest was abortedがspin upに関係ないというのは間違っているっぽいのですが、アプリも #slim3 も手が出せないところで問題が起きてるようです

2010-01-10 09:41:16
higayasuo @higayasuo

1分毎のcronでもspin upが起きてしまうのは事実としてあるのでこれをどう考えるべきか。1:1分以内にspin downが起きる時がある。2:インスタンスのいないリクエストキューに振られた #appengine

2010-01-10 09:47:21
Suguru ARAKAWA @ashigeru

@higayasuo 3: cronは静的にスケジューリングしやすいので、特別なapp server roomに移された #appengine

2010-01-10 09:55:32
higayasuo @higayasuo

@sho235711 spin upを短くするためには余分な初期化をしないだとかJavaならJDOを使わないだとかが考えられます #appengine

2010-01-10 09:56:53