どんどん使おうTraceView

テストで作っていたアプリケーションの起動〜画面が表示されるまで(暗転中)の時間長さが気になってきたので、丁度良いと思い以前に紹介したTraceViewを使って、起動時の処理をプロファイリングしたみたところ、一番時間がかかっているのはXMLをパースしている中でパーサのメソッドを呼び出している箇所だった。(といっても上位10位が全て100msec台なので、それほど重大ではない)

  • 経過時間Top5

スクリーンショット中に見えている計測値の凡例は右端からそれぞれ

    • Time/Call

1回当たりのメソッド実行時間(msec)

    • Calls+RecurCalls/Total

メソッド呼出/再帰呼出の回数合計

    • Exclusive

メソッドの実行時間トータル(msec

    • Excl%

Exclusiveが全体の実行時間の合計に占める割合(%)
である。

上位2つのうち、getDepthは現在パースしている要素の階層(ルート要素は0)、getEventTypeは直近のパースメソッド(next等)で戻ったXMLイベント(整数)を取得するメソッドであり、それぞれ以下のようにhasNextメソッド中で使用されている。

  • XmlResSubtreeParser.java 抜粋
//rootNode  基点となったノード名
//rootDepth 基点となった階層の深度

public boolean hasNext() throws XmlPullParserException {
    if ( this.rootDepth > this.getDepth() ) {
        return false;
    }
    if ( this.getEventType() == XmlResourceParser.END_TAG ) {
        if ( this.getName().equals(this.rootNode)) { 
            return false;
        }
        if ( this.rootDepth >= this.getDepth() ) {
            return false;
        }
    }
    return (this.getEventType() != XmlResourceParser.END_DOCUMENT);
}

このクラスはXMLPullParserのサブツリーだけを読むために用意したパーサの委譲クラスであり、メソッドの殆どの呼び出しを元々のパーサに委譲するが、要素がブレークしたことを判定するためにこのhasNextメソッドを使う。

プロファイル結果を見る限り、回数が多く呼ばれていることにより上位にランクインしていることはほぼ間違いないので、コードを見直して呼び出し回数を減らすようにしてみたのが、以下のコードだ

  • XmlResSubtreeParser.java 改) nextメソッドとhasNextメソッド
public int next() throws XmlPullParserException, IOException {
    this.lastEvent = super.next();
    this.lastDepth = this.getDepth();
    return this.lastEvent;
}

public boolean hasNext() throws XmlPullParserException {
    if ( this.rootDepth > this.lastDepth ) {
        return false;
    }
    if ( this.lastEvent == XmlResourceParser.END_TAG ) {
        if ( this.getName().equals(this.rootNode)) { 
            return false;
        }
        if ( this.rootDepth >= this.lastDepth ) {
            return false;
        }
    }
    return (this.lastEvent != XmlResourceParser.END_DOCUMENT);
}

現在の階層の深さ、イベント状態はnextメソッド等のパースメソッドを呼ばない限りは変化しないはずなので、それぞれフィールドを定義して、(lastDepth、lastEvent)パースメソッド後に更新された値を退避しておき、hasNextメソッドではその退避された値を参照するようにした。

この変更後に再度プロファイリングを実施した結果がこれだ。

1位と2位の二つのメソッドは、ランク圏外となっていることが判る。

では同メソッドの呼出回数はどれだけ少なくなったのだろう。

それぞれ1/4程度に下がったことが判り、それに伴い実行時間そのものも同じ比率で下がっている。

SwingにしろServletにしろ、通常のJavaアプリケーションでは気にしないような小さい部分だが、Androidの場合はこの小さな積み重ねが効いてくるので、計測を実施する意義は十分にあるだろう。

それにしても、高々他のクラスのインスタンスのメソッド呼出しなのに馬鹿にならない時間がかかっているものだ。
あと、実際に試してみて判ったが、古典的な変数のキャッシュ戦略は現在のインタプリタオンリーのDalvikには非常に有効だった。最新のSDKでは試験的にJITを有効にしたビルドを使えるらしいが、性能の向上が待ち遠しい。