最近コツコツGAE/Jでウェブサービスを作っているぉぅぇぃです。

利用者数がちょこちょこ増えて、

いい感じ(?)にQuota(割り当て)の数値が上がってきました。っと言っても、

一番高いCPU Timeも無料割当分の１０％くらいしか来てないのですが、

気が早いぉぅぇぃは、

「おろおろ、おろおろ、ユーザが１０倍増えたら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();

    //何かの処理その１

    qc.check("何かの処理その１");

    //何かの処理その２

    qc.check("何かの処理その２");

    //何かの処理その３

    qc.check("何かの処理その３");

そうしたら、こんな感じのログが出てきます。

DEBUG – 何かの処理その１:xxxcpu_ms
DEBUG – 何かの処理その２:yyycpu_ms
DEBUG – 何かの処理その３:zzzcpu_ms

こんな感じで、処理に費やしたCPU時間は大体分かるようになります。

しかし、どんな仕組みかはよく分かりませんが、

QuotaServiceで計算したCPU時間とログで表示されるCPU時間は合わない。

１桁違う…くらい合わないのですが、まあ、

各プロセスのパフォーマンスを測定するのに十分な数値じゃないかと思います。

後、全く同じ処理でも、ほーんーとーうーにかなりバラツキが大きいので、

何回か実行して、平均で見たほうがいいでしょう。

ちなみに、ここらへんのチューニングは、結構効果があります。

意外なところに無駄な処理が行ってたり、妙に時間かかるな…っと思ったら、

構文のミスでバグに近いコードがあったり…まあ、色々ですね。

どれくらい効果があるか…の一例ですが、今回チューニングしたコートだとこんな感じ。
(*クローンによる同じ同等な定期処理です)

ビフォー：1674ms 3928cpu_ms 3181api_cpu_ms 0kb
アフター：635ms 259cpu_ms 95api_cpu_ms 0kb

…。

ァッハッハ、元々はどれほど雑で無駄が多いコードかが分かりますね。

しかし、元々のコードも動いてなかった…というわけではなく、

非常に効率が悪いのですが、一応フツウに動いていました。

しかし、アフターのコードは、ビフォーのコードと比べたら、

ランニングコストは十分の一…だよね。

そう考えますと、これからの時代では、

パフォーマンスが抜群のコードが書ける腕の良いプログラマーの価値は、

今よりも高くなていくじゃないかと思います。

そういう意味では、これからのIT業界で生き残るためには、

しっかり腕を磨くことは重要になりますね。

そう考えたら、２０−３０年前から存在しているような古いスタイルの情報教育…ではなく、

最先端なやり方を教えてくれるところで学びたいよね。

IT業界を目指したい方は、良かったらKCGやKCGIも見てみると良いかもしれません。

超先端とは言いませんが、かなり良い線には行ってると思いますよ。