StrictModeでパフォーマンスをチューニングする

Gingerbreadの新機能の一つとして「StrictMode」が導入されましたので、実際に使用して検証してみました。

StrictModeとは?

  • アプリケーションの動作をもっさりさせる原因となる、 ディスクやネットワークへのアクセスを検知するための仕組み。
  • 「スレッドや仮想マシンのポリシー」という形で、何を検知するかを決めることができます。
  • デフォルトでは下記のようなものが検知できます。
    • ディスクの読み込み、書き込み
    • ネットワークの使用
    • 違反:ログ、クラッシュ、dropbox、邪魔なダイアログ
  • 検知は、ディスク(java.io.*, android.database.sqlite.*, etc)やネットワーク(java.net.*)をフックすることで行われます。

StrictModeの利点

  • パフォーマンスの劣化につながる要素(ディスクアクセス、ネットワークアクセス、データベースカーソルのリークなど)を特定することができます。
  • 特定した結果をlogcatで表示することができ、特殊なログ解析ツール等は不要。
  • 次期バージョン「Honeycomb」ではメイン(UI)スレッドでネットワークのリクエストを行うとfatalエラー(例えターゲットがHoneycomb以前だとしても)となります。したがって、StrictModeは次期バージョンへアプリを対応させる上で、重要なツールとなります。

StrictModeの欠点

  • パフォーマンスを劣化させる全てを検知できる訳ではない。
  • 正常なアクセスもポリシー違反として検知されることがある。
  • 将来において、より多くの種類の検知を行うようになるため、リリース時には手動で無効化しておく手間がかかる。

StrictModeの使いどころ

  • ユーザエクスペリエンスに問題がある(もっさりしすぎている)と感じた場合にのみ、使うと良いです。
  • 将来的にはコンパイルエラーを特定するためのツールの一つになる可能性があります(UIスレッドでアクセスしている部分の特定など)。

StrictMode関連クラス・メソッド一覧

StrictModeクラス:

  • enableDefaults() - おすすめのStrictModeのデフォルト設定、ポリシー違反はログに出力される。
  • allowThreadDiskReads():getThreadPolicy() -> ディスク読み込みの許可 -> setThreadPolicy() までやってくれるラッパー。
  • allowThreadDiskWrites():getThreadPolicy() -> ディスク読み込み&書き込みの許可 -> setThreadPolicy() までやってくれるラッパー。
  • getThreadPolicy():現在のスレッドのポリシーを取得する。
  • getVmPolicy():現在のVMのポリシーを取得する。
  • setThreadPolicy(StrictMode.ThreadPolicy policy):現在のスレッドに指定のポリシーを適用する。
  • setVmPolicy(StrictMode.VmPolicy policy):現在のVMに指定のポリシーを適用する。

StrictMode.ThreadPolicy.Builderクラス - スレッドに適用されるポリシー

  • build() : ThreadPolicyのインスタンスを生成する。
  • detectAll():潜在的に疑いのある全ての事象を検知する。
  • detectDiskReads():ディスクの読み込みを検知する
  • detectNetwork():ネットワーク操作を検知する
  • penaltyDeath():違反したプロセス全体をクラッシュする。
  • penaltyDialog():違反として検知した煩わしいダイアログを表示する。
  • penaltyDropBox():ポリシーに違反したDropboxスタックトレースとタイミングデータのログを有効にする。
  • penaltyLog():システムログに違反検知ログを出力する。
  • permitAll():全ての検知を無効にする。
  • permitDiskReads():ディスクの読み込み検知を無効にする。
  • permitDiskWrites():ディスクの書き込み検知を無効にする。
  • permitNetwork():ネットワークの操作検知を無効にする。

StrictMode.VmPolicy.Builderクラス - VMプロセス中の全てのスレッドに適用されるポリシー

  • build() :VMインスタンスを生成する。
  • detectAll():潜在的に疑いのある全ての事象を検知する。
  • detectLeakedSqlLiteObjects():SQLiteCursor または 他のSQLiteのオブジェクトがクローズされずにファイナライズされた場合に検知する。
  • penaltyDeath():違反したプロセス全体をクラッシュする。
  • penaltyDropBox():ポリシーに違反したDropboxスタックトレースとタイミングデータのログを有効にする。
  • penaltyLog():システムログに違反検知ログを出力する。

StrictModeで実行してみる

下記のようにonCreateで設定するだけでOK。結果はLogcatで確認。

// StrictModeはデバッグ時のみ使用すること
private final boolean DEVELOPER_MODE = true;

@Override
public void onCreate(Bundle savedInstanceState) {
    if (DEVELOPER_MODE) {
	StrictMode.setThreadPolicy(new StrictMode.ThreadPolicy.Builder()
		    	.detectAll()
		    	.penaltyLog()
		    	.build());
	StrictMode.setVmPolicy(new StrictMode.VmPolicy.Builder()
		    	.detectAll()
		    	.penaltyLog()
		    	.penaltyDeath()
		    	.build());
    }
    super.onCreate(savedInstanceState);
    setContentView(R.layout.main);
      :
    (以下略)

または

// StrictModeはデバッグ時のみ使用すること
private final boolean DEVELOPER_MODE = true;

@Override
public void onCreate(Bundle savedInstanceState) {
    if (DEVELOPER_MODE) {
	StrictMode.enableDefaults();
    }
    super.onCreate(savedInstanceState);
    setContentView(R.layout.main);
      :
    (以下略)
実行結果

※個人的に随分昔に作成した非常に残念で恥ずかしいコードを利用

12-18 23:30:34.588: DEBUG/StrictMode(337): StrictMode policy violation; ~duration=6604 ms: android.os.StrictMode$StrictModeNetworkViolation: policy=23 violation=4
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.os.StrictMode$AndroidBlockGuardPolicy.onNetwork(StrictMode.java:758)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at java.net.InetAddress.lookupHostByName(InetAddress.java:488)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at java.net.InetAddress.getAllByNameImpl(InetAddress.java:294)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at java.net.InetAddress.getAllByName(InetAddress.java:256)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at org.apache.harmony.luni.internal.net.www.protocol.http.HttpConnection.<init>(HttpConnection.java:68)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at org.apache.harmony.luni.internal.net.www.protocol.http.HttpConnection.<init>(HttpConnection.java:48)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at org.apache.harmony.luni.internal.net.www.protocol.http.HttpConnection$Address.connect(HttpConnection.java:298)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at org.apache.harmony.luni.internal.net.www.protocol.http.HttpConnectionPool.get(HttpConnectionPool.java:89)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at org.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnectionImpl.getHttpConnection(HttpURLConnectionImpl.java:285)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at org.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnectionImpl.makeConnection(HttpURLConnectionImpl.java:267)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at org.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnectionImpl.retrieveResponse(HttpURLConnectionImpl.java:1018)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at org.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnectionImpl.getInputStream(HttpURLConnectionImpl.java:510)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at java.net.URL.openStream(URL.java:645)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at jp.naoki.seto.ResultList$ViewItemAdapter.getView(ResultList.java:141)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.widget.AbsListView.obtainView(AbsListView.java:1418)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.widget.ListView.makeAndAddView(ListView.java:1745)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.widget.ListView.fillDown(ListView.java:670)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.widget.ListView.fillFromTop(ListView.java:727)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.widget.ListView.layoutChildren(ListView.java:1598)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.widget.AbsListView.onLayout(AbsListView.java:1248)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.view.View.layout(View.java:7175)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.widget.FrameLayout.onLayout(FrameLayout.java:338)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.view.View.layout(View.java:7175)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.widget.LinearLayout.setChildFrame(LinearLayout.java:1254)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.widget.LinearLayout.layoutVertical(LinearLayout.java:1130)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.widget.LinearLayout.onLayout(LinearLayout.java:1047)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.view.View.layout(View.java:7175)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.widget.FrameLayout.onLayout(FrameLayout.java:338)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.view.View.layout(View.java:7175)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.view.ViewRoot.performTraversals(ViewRoot.java:1140)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.view.ViewRoot.handleMessage(ViewRoot.java:1859)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.os.Handler.dispatchMessage(Handler.java:99)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.os.Looper.loop(Looper.java:123)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at android.app.ActivityThread.main(ActivityThread.java:3647)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at java.lang.reflect.Method.invokeNative(Native Method)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at java.lang.reflect.Method.invoke(Method.java:507)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:839)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:597)
12-18 23:30:34.588: DEBUG/StrictMode(337):     at dalvik.system.NativeStart.main(Native Method)

パフォーマンスのチューニング方法

ログを解析する
StrictMode policy violation; ~duration=6604 ms: android.os.StrictMode$StrictModeNetworkViolation: policy=23 violation=4
     at android.os.StrictMode$AndroidBlockGuardPolicy.onNetwork(StrictMode.java:758)

ネットワーク関連の処理で、処理時間が(duration)が6604ms = 6.6sec !? もかかっている・・・

DEBUG/StrictMode(337):     at java.net.URL.openStream(URL.java:645)
DEBUG/StrictMode(337):     at jp.naoki.seto.ResultList$ViewItemAdapter.getView(ResultList.java:141)

問題の場所。どうやら、ResultList.java 141行目のViewItemAdapterクラス内のgetViewでURL.openStreamを実行している。つまり、UIスレッド上に展開されたリストビューで、ネットワークアクセスをしているようだ。

コードを見直す

ResultList.java

89:    // リストビューアイテム表示アダプタ
90:    private static class ViewItemAdapter extends BaseAdapter {
91:
(前略)
119:
120:	public View getView(int position, View convertView, ViewGroup parent) {
121:
(中略)
139:	    try {
140:		url = new URL(result.get(position).get("smallImageUrl").toString());
141:		is = url.openStream();
142:	    } catch (MalformedURLException e) {

確かにソースを確認すると、メインスレッド上のgetViewで(つまり、リストビューの1行表示毎に)実行しており、パフォーマンスを著しく落としている原因になっている。
このように、ログからパフォーマンスを著しく落とす原因(上記の場合、メインスレッド上のネットワークアクセスを行っている箇所)を特定し、これらをバックグラウンドプロセス等に置き換えることで、アプリのパフォーマンスを向上させることができると思われる。
※ちなみに、このコードはHoneycombではfatal errorとなって、コンパイルすら出来なくなるでしょう。

Android端末はフラッシュメモリを内蔵しているので、ディスクアクセスは遅くないのではないか?という疑問

大抵の場合(容量が非常に限られた)内蔵フラッシュメモリを使用している間は、ディスクアクセスは非常に早いです。但し、他のプロセスからバックグラウンドでI/O処理が発生した場合など、劇的に遅くなるケースも多々存在します。したがって、「ディスクアクセスは非常に遅い」と仮定した設計が望ましいと思われます。

StrictModeはセキュリティのメカニズムではない

StrictModeはセキュリティのメカニズムではないので、全てのディスクやネットワークへのアクセスを検知する訳ではなく、保証もされません。Binderの呼び出し時にプロセス境界の向こう側に状態を伝播しますが、それでもベストエフォート型メカニズムに過ぎません。特にJNIからのディスクやネットワークアクセスは必ずしも検知されません。

パフォーマンス改善のためにStrictMode以外で考慮すべきこと

使用するAPIを変えることでパフォーマンスを改善出来ることがあります。例えば、新しいメソッドである SharedPreferences.Editor.apply() は 戻り値を必要としない場合は、同クラスの commit() よりもパフォーマンスが良くなります。

文責:技術部 瀬戸 直喜(前・日本Androidの会四国支部長/情報セキュリティスペシャリスト)