ページ更新: 2012-01-13 (金) (2082日前)

(2006-05-28 作成)

System#nanoTime() (J2SE 5.0以後) が存在すれば使用し、存在しなければ System#currentTimeMillis() (Java 1.0〜) を使う。

目次

[編集]

目的 #

J2SE 1.4.X 用にコンパイルされたコードの、ある処理の所要時間を計測する。

J2SE 1.4.X上で動作させるときはSystem#currentTimeMillis() を使い、 J2SE 5.0上で実行されたときはより精度の高い System#nanoTime() を使いたい。

[編集]

設計・分析 #

単純にメソッドを切り替えても良いが、もう少し抽象度を上げたい。

そこで、Apache Commons Lang 2.0 の org.apache.commons.lang.time.StopWatch、 あるいは .Net Framework 2.0 の System.Diagnostics.StopWatch のように StopWatchクラスを作って、それで詳細を隠すことにする。

StopWatchクラスの実装を2つ用意しても良いが(StopWatch インターフェイス、StopWatchFactoryクラス、MilliStopWatchクラス、NanoStopWatchクラス)

interface StopWatch
    void start();
    void stop();
    double getTime();

class MilliStopWatch implements StopWatch

class NanoStopWatch implements StopWatch

class StopWatchFactory
    static StopWatch getInstance() {
        if (JVMが5.0以上) {
           new NanoStopWatch();
        } else {
            new MilliStopWatch();
        }
    }
}

(または、Calendarクラスのように、StopWatchクラスがStopWatchインターフェイス、StopWatchFactoryクラスを兼用しても良い)

System#nanoTime()を呼ぶNanoStopWatchクラスはJ2SE 5.0で、-source 1.5でコンパイルする必要がある。

Antでの自動化はたぶん可能、でも煩雑になる。 EclipseでJ2SE 1.4と5.0を同一のプロジェクトに混在するのはたぶん無理。 別途、プロジェクトを分離するのも煩雑で、扱いにくくなる。引き継ぎも面倒

そもそも、JVMのバージョン判別も面倒。java.versionは"1.5.0_07"の形式なので、パースする必要がある。 Sunのことだから、いきなり "6.0_03" なんてバージョン番号に変えるかも知れないし。(まあ内部バージョンの形式は変更しないと思うが)

Aspectは別途ツールやライブラリが必要 (AspectJ, javaassist)だし、 バイトコードの差し替え(J2SE 5.0 + -javaagent + Apache BCEL) はJ2SE 5.0以後だから今回の用途には使えない。

そこで、リフレクションを使い、System#nanoTimeメソッドが存在すれば使い、そうでなければSystem#currentTimeMillisメソッドを使うようにしてみた。

[編集]

コード #

package jp.discypus.time;

import java.lang.reflect.InvocationTargetException;
import java.lang.reflect.Method;

/**
 * 処理に掛かった時間を計測するストップウオッチ。
 * 
 * 精度の高い {@link System#nanoTime()} を使う。
 * 使用できない場合 (J2SE 1.4とか) では [@link System#currentTimeMillis()} を使う。
 */
public final class StopWatch {
    /** 未計測を示す定数 */
    private static final long NOT_ASSIGNED = -1;
    
    /** ナノ秒とミリ秒の相互変換用の定数。10^-9 と 10-^3の差。*/
    private static final double NANO_TO_MILLI = 1000 * 1000;
    
    /** nanoTimeをリフレクションで呼び出すときの引数 */
    private static final Object[] NULL_ARGS = new Object[]{};

    /** System.nanoTimeメソッドが使用可能なら保持する */
    private static final Method nanoTime;
    
    /** スタティックイニシャライザ。初めてクラスを使うとき、System.nanoTimeメソッドを調査する */
    static {
        nanoTime = checkNanoTimeMethod();
    }
    
    /** System.nanoTimeメソッドを返す。使用できなければnullを返す */
    private static final Method checkNanoTimeMethod() {
        final String className = "java.lang.System";
        final String methodName = "nanoTime";
        final Class[] methodArgsTypes = new Class[]{};

        try {
            /* nanoTimeメソッドを得る */
            final Class clazz = Class.forName(className);
            final Method method = clazz.getMethod(methodName, methodArgsTypes);
            
            /** nanoTimeメソッドを実行する。結果が帰ってこなければ使用不可と見なす */
            final Object result = method.invoke(null, NULL_ARGS);
            if (result == null) {
                return null;
            }
            return method;
        } catch (final ClassNotFoundException e) {
            /** メソッドの取得やメソッドの実行で例外が発生したときは使用不可と見なす。他の例外も同様。*/
            return null;
        } catch (final SecurityException e) {
            return null;
        } catch (final NoSuchMethodException e) {
            return null;
        } catch (final IllegalArgumentException e) {
            return null;
        } catch (final IllegalAccessException e) {
            return null;
        } catch (final InvocationTargetException e) {
            return null;
        }
    }

    /** 計測開始時の時間 */
    private long start = NOT_ASSIGNED;
    
    /** 計測終了時の時間 */
    private long stop = NOT_ASSIGNED;
    
    /** コンストラクタ */
    public StopWatch() {
    }
    
    /** 計測を開始 */
    public void start() {
        start = hasNanoTime() ? nanoTime() : System.currentTimeMillis();
        stop = NOT_ASSIGNED;
    }

    /** 計測を終了 */
    public void stop() {
        stop = hasNanoTime() ? nanoTime() : System.currentTimeMillis();
    }

    /**
     * 所要時間を返す。
     * 未計測であれば0を、計測中であれば現在までの経過時間を、計測終了であれば所要時間を返す。
     * @return
     *  整数部=ミリ秒、小数部:サブミリ秒
     */
    public double getTime() {
        if (stop == NOT_ASSIGNED) {
            if (start == NOT_ASSIGNED) {
                // 未計測
                return 0;
            } else {
                // 計測中
                if (hasNanoTime()) {
                    return (nanoTime() - start) / NANO_TO_MILLI;
                } else {
                    return System.currentTimeMillis() - start;
                }
            }
        } else {
            // 計測終了
            if (hasNanoTime()) {
                return (stop - start) / NANO_TO_MILLI;
            } else {
                return stop - start;
            }
        }
    }

    /** nanoTimeが使用可能であればtrueを返す */
    private boolean hasNanoTime() {
        return nanoTime != null;
    }
    
    /**
     * nanoTimeメソッドを実行する。リフレクションを使用。
     *
     * 実行前に {@link #canUseNanoTime()} を確認すること。
     * @return
     *  0: nanoTimeが実行できなかった
     */
    private long nanoTime() {
        try {
            final Object result = nanoTime.invoke(null, NULL_ARGS);
            if (result == null) {
                return 0;
            } else {
                return ((Long) result).longValue();
            }
        } catch (final IllegalArgumentException e) {
            return 0;
        } catch (final IllegalAccessException e) {
            return 0;
        } catch (final InvocationTargetException e) {
            return 0;
        }
    }
    
    /** サンプルコード */
    public static void main(final String[] args) {
        final StopWatch watch = new StopWatch();
        double result;

        //
        result = watch.getTime();
        System.out.println("result=" + result);

        //
        watch.start();
        result = watch.getTime();
        System.out.println("result=" + result);

        //
        sleep(500);
        result = watch.getTime();
        System.out.println("result=" + result);

        //
        sleep(500);
        watch.stop();
        result = watch.getTime();
        System.out.println("result=" + result);
    }

    /** ミリ秒、スリープする。サンプルコードで使用 */
    private static final void sleep(final long millis) {
        try {
            Thread.sleep(millis);
        } catch (final InterruptedException ignore) {
        }
    }
}
[編集]

実行結果 #

Windows XP、Pentium4-2.6GHz

  • WinAPI GetTickCount() の分解能は 15.6ms。
    • System.currentTimeMillis() と Thread.sleep(long)では、このカウンタ(と同じ精度のカウンタ)が用いられているようだ。
  • WinAPI QueryPerformanceFrequency() (高分解能パフォーマンスカウンタ) の分解能は 1/2.6GHz = 0.385ns。

JDK 1.5.0_07 public JRE。nanoTime() が使われている。Thread.sleep(long) の誤差がわかる。

result=0.0
result=0.087252
result=486.103196
result=985.084854

J2SDK 1.4.2_11 public JRE。currentTimeMillis() が使われている。

result=0.0
result=0.0
result=500.0
result=1000.0
[編集]

問題点 #

リフレクションでメソッドを呼び出したときのオーバーヘッド。

まともに計測していない(同一PCで計測したワケじゃない)のだが、 nanoTime()を連続で呼び出すと300〜400ns、Visual Studio 2005 Professional の VC++ で QueryPerformanceCounter を連続で呼び出すと300ns前後の時間が掛かる。 上記のStopWatchクラスでは800〜1000ns程度かかるので、リフレクションのオーバーヘッドは500nsくらいありそうだ。

  • この当時に使ったPC のCPU は Intel Pentium 4-2.6GHz, Pentium 4-2.8GHz とか。あとで Intel Core2Duo E6600, Core2Quad Q6700 も使ったような気がする。
  • VM は Sun の HotSpot Server VM (JDKに付属する。-server オプションが使える) を使ったと思う。

バイトコードの差し替え(J2SE 5.0 + -javaagent + J2SE付属のApache BCEL、あるいはカスタムクラスローダ + BCEL/javaassist/ASM、あるいはCGLIB) で高速化できると思う。

参考:

[編集]

追記 #

[編集]

java.lang.Proxy でもっと楽に出来ないか? 高速化できないか? (2009-06-15) #

ふむ。この方法も使えるかも。

[編集]

雑感 2008-07-09 #

JNIのオーバーヘッドを調べとく必要があるなあ。JNI経由でQueryPerformanceCounter呼んでみなくては。

もっとも、このStopWatchクラスは1.0ms前後かかる処理を修正しつつ0.05〜0.1msくらい所要時間の変化に一喜一憂するために使ってるから、 1000ns = 1 micro-sec = 0.001 milli-sec のオーバーヘッド = 0.05 milli-secの2% なので、まあ許容範囲かなあ。

[編集]

developerWorks「確実な Java ベンチマーク」「InfoQ: Perf4Jを使ったパフォーマンス解析とモニタリング」 #

自分は最大値・最小値・中央値、標本標準偏差を求めるコードをアプリケーションに入れてるけど、この処理は汎用化したいところ。

[編集]

虎塚「JDKの時間計測まわりのコードを読んでみる」 (2011-02-27) #

native コードがどのようになっているか、Windows, Linux, Solaris で調べてみたとのこと。

[編集]

音宮志久のプログラム日記「QueryPerformanceCounterの精度問題まとめ」 (2012-01-13) #

[編集]

Visual C++: rdtsc, rdtscp Intrinsics (2012-01-13) #

MSDN Library - Compiler Intrinsics: