最近コツコツGAE/Jでウェブサービスを作っているぉぅぇぃです。
利用者数がちょこちょこ増えて、
いい感じ(?)にQuota(割り当て)の数値が上がってきました。っと言っても、
一番高いCPU Timeも無料割当分の10%くらいしか来てないのですが、
気が早いぉぅぇぃは、
「おろおろ、おろおろ、ユーザが10倍増えたらOver Quotaでサービス停止になるじゃなイカ!?」
ということで、今までの適当コードを見直すことにしました。
っと言っても、CPU TIMEの場合は要するに情報を処理するのに時間かかりすぎた…、
ということなので、できるだけ処理を簡素化し、無駄な処理を省き、
データストアへのアクセスを極力減らして、
キーの取得だけで済ませるものはキーだけを取って、
データが短い文字列や数字なら、キーの中に入れてみるとか、
キャッシュ出来そうなものは可能なかぎりキャッシュして、
システム内でハンドルしてた処理を、可能ならば外部のシステムに委譲してみる…とか。
まあ、色々ですね。
ぉぅぇぃの持論ですが、
ダイエットしたいなら、毎日食事メモを取って、体重を測ってデータを取らなければならない。
家計を改善したいのであれば、毎日家計簿を付けて、定期的に分析をしなければならない、
同じく、リソースを節約したいのであれば、まずは測定しないと、話が始まらないです。
で、当たり前のことですが、GAE/JはCPUの使用状況をモニタリングするためのAPIがあります。
サンプルコードはこんな感じ。
→http://code.google.com/intl/en/appengine/docs/quotas.html
In the Java API, the com.google.appengine.api.quota package provides the QuotaService interface (with an implementation and factory) with several methods. See the Javadoc for details.
import com.google.appengine.api.quota.QuotaService;
import com.google.appengine.api.quota.QuotaServiceFactory;
// ...
QuotaService qs = QuotaServiceFactory.getQuotaService();
long start = qs.getCpuTimeInMegaCycles();
doSomethingExpensive();
long end = qs.getCpuTimeInMegaCycles();
double cpuSeconds = qs.convertMegacyclesToCpuSeconds(end - start);
まあ、こんな感じですが、毎回毎回これを書くのがさすがに面倒くさい…というか、
コードのメンテナンスが大変なので、
シンプルにCPU TIME測定してくれるQuotaCheckerクラスを作ってみた。
package aaa.bbb.ccc;
import com.google.appengine.api.quota.QuotaService;
import com.google.appengine.api.quota.QuotaServiceFactory;
import com.google.appengine.repackaged.org.apache.commons.logging.Log;
import com.google.appengine.repackaged.org.apache.commons.logging.LogFactory;
public class QuotaChecker {
private static QuotaService quotaService = QuotaServiceFactory
.getQuotaService();
private Log log = LogFactory.getLog(QuotaChecker.class);
private long start = -1L;
private long end = -1L;
public QuotaChecker() {
}
public void start(){
log.debug("start()");
start = quotaService.getCpuTimeInMegaCycles();
}
public void check(String message) {
end = quotaService.getCpuTimeInMegaCycles();
if (start != -1L) {
double time =
quotaService.convertMegacyclesToCpuSeconds(end - start);
log.debug(message+":"+(int)(time*1000)+"cpu_ms");
}
start = end;
}
}
使い方はこんな感じ。
QuotaChecker qc = new QuotaChecker();
qc.start();
//何かの処理その1
qc.check("何かの処理その1");
//何かの処理その2
qc.check("何かの処理その2");
//何かの処理その3
qc.check("何かの処理その3");
そうしたら、こんな感じのログが出てきます。
DEBUG – 何かの処理その1:xxxcpu_ms
DEBUG – 何かの処理その2:yyycpu_ms
DEBUG – 何かの処理その3:zzzcpu_ms
こんな感じで、処理に費やしたCPU時間は大体分かるようになります。
しかし、どんな仕組みかはよく分かりませんが、
QuotaServiceで計算したCPU時間とログで表示されるCPU時間は合わない。
1桁違う…くらい合わないのですが、まあ、
各プロセスのパフォーマンスを測定するのに十分な数値じゃないかと思います。
後、全く同じ処理でも、ほーんーとーうーにかなりバラツキが大きいので、
何回か実行して、平均で見たほうがいいでしょう。
ちなみに、ここらへんのチューニングは、結構効果があります。
意外なところに無駄な処理が行ってたり、妙に時間かかるな…っと思ったら、
構文のミスでバグに近いコードがあったり…まあ、色々ですね。
どれくらい効果があるか…の一例ですが、今回チューニングしたコートだとこんな感じ。
(*クローンによる同じ同等な定期処理です)
ビフォー:1674ms 3928cpu_ms 3181api_cpu_ms 0kb
アフター:635ms 259cpu_ms 95api_cpu_ms 0kb
…。
ァッハッハ、元々はどれほど雑で無駄が多いコードかが分かりますね。
しかし、元々のコードも動いてなかった…というわけではなく、
非常に効率が悪いのですが、一応フツウに動いていました。
しかし、アフターのコードは、ビフォーのコードと比べたら、
ランニングコストは十分の一…だよね。
そう考えますと、これからの時代では、
パフォーマンスが抜群のコードが書ける腕の良いプログラマーの価値は、
今よりも高くなていくじゃないかと思います。
そういう意味では、これからのIT業界で生き残るためには、
しっかり腕を磨くことは重要になりますね。
そう考えたら、20−30年前から存在しているような古いスタイルの情報教育…ではなく、
最先端なやり方を教えてくれるところで学びたいよね。
IT業界を目指したい方は、良かったらKCGやKCGIも見てみると良いかもしれません。
超先端とは言いませんが、かなり良い線には行ってると思いますよ。