Java Tips | 日付・時間：実行時間計測

Java Java
スポンサーリンク

「実行時間計測」で何を知りたいのか

実行時間計測は、一言でいうと「この処理、実際どれくらい時間かかっているの？」を数字で見える化することです。
なんとなく「遅い気がする」ではなく、「平均 120ms」「ピーク時は 3 秒」といった形で話せるようにするための技術です。

業務システムでは、外部API、DBアクセス、バッチ処理、レポート生成など、重くなりやすいポイントがたくさんあります。
そこに「実行時間計測」を仕込んでおくと、性能問題やセキュリティインシデントの調査で、非常に強い武器になります。

実行時間計測の基本：前後を挟んで差を取る

一番シンプルなパターン

実行時間計測の基本はとてもシンプルです。

処理の前で「開始時刻」を取る。
処理の後で「終了時刻」を取る。
終了 − 開始 ＝ 実行時間。

まずは System.nanoTime() を使った、最小の例を見てみましょう。

public class SimpleExecutionTime {

    public static void main(String[] args) {
        long start = System.nanoTime();

        doWork();

        long end = System.nanoTime();

        long elapsedNanos = end - start;
        double elapsedMillis = elapsedNanos / 1_000_000.0;

        System.out.println("実行時間(ナノ秒): " + elapsedNanos);
        System.out.println("実行時間(ミリ秒): " + elapsedMillis);
    }

    private static void doWork() {
        try {
            Thread.sleep(500); // 0.5秒の処理だと思ってください
        } catch (InterruptedException e) {
            Thread.currentThread().interrupt();
        }
    }
}
Java

ここで重要なのは、「測りたい処理を start と end で“挟む”」という感覚です。
この挟み方さえ身につけば、どんな処理でも実行時間を測れるようになります。

なぜ nanoTime を使うのか

currentTimeMillis ではダメなの？

System.currentTimeMillis() でも同じように差を取れば時間は出ますが、実行時間計測には向きません。
理由は、これは「壁時計の時刻」であり、OS の時刻調整（NTP など）で前後にジャンプする可能性があるからです。

一方 System.nanoTime() は、「ある基準点からの経過ナノ秒」で、単調に増加することが保証されています。
「今何時か」は分かりませんが、「どれくらい時間が経ったか」を測るには最適です。

実行時間計測では、「時刻」ではなく「経過時間」が欲しいので、基本的には System.nanoTime() を使う、と覚えておいてください。

Duration を使って「時間」として扱う

生の long ではなく Duration にするメリット

ナノ秒の差を long のまま扱ってもよいのですが、
「時間」として扱うなら java.time.Duration を使うと、コードの意図がとても読みやすくなります。

import java.time.Duration;

public class ExecutionTimeWithDuration {

    public static void main(String[] args) {
        long start = System.nanoTime();

        doWork();

        long end = System.nanoTime();

        Duration duration = Duration.ofNanos(end - start);

        System.out.println("Duration      : " + duration);
        System.out.println("ミリ秒        : " + duration.toMillis());
        System.out.println("秒(小数あり)  : " + duration.toNanos() / 1_000_000_000.0);
    }

    private static void doWork() {
        try {
            Thread.sleep(750); // 0.75秒
        } catch (InterruptedException e) {
            Thread.currentThread().interrupt();
        }
    }
}
Java

Duration を使うと、ミリ秒、秒、分などへの変換がメソッドで書けます。
「実行時間を Duration で持つ」という癖をつけておくと、ログ、メトリクス、画面表示など、どこにでも柔軟に流用できます。

実務でよくやる「実行時間ログ」の書き方

try-finally で「必ず計測する」

業務コードでは、「例外が出ても実行時間をログに残したい」ということがよくあります。
そのときは try-finally で計測範囲を挟むのが定番です。

import java.time.Duration;

public class LoggingExecutionTime {

    public static void main(String[] args) {
        long start = System.nanoTime();
        try {
            doBusinessLogic();
        } finally {
            long end = System.nanoTime();
            Duration d = Duration.ofNanos(end - start);
            System.out.println("[LOG] doBusinessLogic 実行時間(ms): " + d.toMillis());
        }
    }

    private static void doBusinessLogic() {
        // ここに業務処理を書く
        try {
            Thread.sleep(300);
        } catch (InterruptedException e) {
            Thread.currentThread().interrupt();
        }
    }
}
Java

finally は、正常終了でも例外でも必ず実行されます。
そのため、「どんな終了パスでも実行時間を記録できる」というのが大きなメリットです。

このパターンを一度体で覚えてしまうと、「ここ遅そうだな」と思った場所に、すぐ実行時間計測を差し込めるようになります。

小さな「実行時間計測ユーティリティ」を作る

Runnable を受け取るユーティリティ

毎回 start/end を書くのが面倒なら、「処理を渡したら実行時間を測ってくれる」ユーティリティを作るのも手です。

import java.time.Duration;

public class ExecutionTimer {

    public static Duration measure(Runnable task) {
        long start = System.nanoTime();
        try {
            task.run();
        } finally {
            long end = System.nanoTime();
            return Duration.ofNanos(end - start);
        }
    }
}
Java

使い方はこうなります。

public class ExecutionTimerExample {

    public static void main(String[] args) {
        Duration d = ExecutionTimer.measure(() -> {
            doWork();
        });

        System.out.println("実行時間(ms): " + d.toMillis());
    }

    private static void doWork() {
        try {
            Thread.sleep(400);
        } catch (InterruptedException e) {
            Thread.currentThread().interrupt();
        }
    }
}
Java

「この処理の実行時間を測りたい」と思ったら、
その処理をラムダで measure に渡すだけです。

実務では、これをもう少し拡張して「処理名も一緒にログに出す」「例外もログに含める」といった形にしておくと、性能調査や障害調査でかなり役に立ちます。

区間ごとの実行時間を測る（ステップ分解）

どの部分が遅いのかを切り分ける

「全体で 3 秒かかっている」のは分かっても、「どこが遅いのか」が分からないと改善できません。
そのときは、処理をステップに分けて、それぞれの実行時間を測ります。

import java.time.Duration;

public class StepExecutionTime {

    public static void main(String[] args) {
        long startAll = System.nanoTime();

        long s1 = System.nanoTime();
        step1();
        long e1 = System.nanoTime();

        long s2 = System.nanoTime();
        step2();
        long e2 = System.nanoTime();

        long s3 = System.nanoTime();
        step3();
        long e3 = System.nanoTime();

        long endAll = System.nanoTime();

        System.out.println("step1(ms): " + Duration.ofNanos(e1 - s1).toMillis());
        System.out.println("step2(ms): " + Duration.ofNanos(e2 - s2).toMillis());
        System.out.println("step3(ms): " + Duration.ofNanos(e3 - s3).toMillis());
        System.out.println("total(ms): " + Duration.ofNanos(endAll - startAll).toMillis());
    }

    private static void step1() {
        sleep(200);
    }

    private static void step2() {
        sleep(500);
    }

    private static void step3() {
        sleep(300);
    }

    private static void sleep(long millis) {
        try {
            Thread.sleep(millis);
        } catch (InterruptedException e) {
            Thread.currentThread().interrupt();
        }
    }
}
Java

これで、「step2 が一番重い」「step1 はほとんど問題ない」といったことが一目で分かります。
実行時間計測は、「全体」と「部分」の両方を測ることで、初めて本当の威力を発揮します。

セキュリティ・運用の観点から見た実行時間計測

性能問題とインシデントの“証拠”を残す

セキュリティインシデントや障害調査では、「いつから遅くなったか」「どの処理が遅いか」が重要な手がかりになります。
実行時間をログに残しておけば、例えば次のようなことが分かります。

ある日から特定の外部APIの実行時間が急に伸びている。
ピーク時間帯だけ DB クエリの実行時間が跳ね上がっている。

これは、外部サービスの障害、ネットワークの問題、DoS攻撃の兆候などを見つけるうえで非常に有効です。

測りすぎない、というバランス感覚

一方で、あらゆる処理に実行時間計測を入れすぎると、ログが膨れ上がり、逆にシステム全体の性能を落とすこともあります。
実務では、例えば次のような方針を取ります。

重要な処理（外部API、DBアクセス、バッチ処理など）に絞って計測する。
ログレベルや設定で「どこまで計測するか」を切り替えられるようにする。
ログフォーマットを統一して、後から集計・可視化しやすくする。

実行時間計測は、「性能とセキュリティのための観測装置」です。
どこをどの粒度で測るかは、設計の一部として意識的に決めていくと良いです。

まとめ：実行時間計測で身につけてほしい感覚

実行時間計測は、「処理の前後で時間を取り、その差を Duration として扱う」だけのシンプルな技術です。
でも、その中に大事な考え方が詰まっています。

処理時間を測るときは System.nanoTime() を使う。
差分は Duration にして、「時間」として扱う。
try-finally や小さなユーティリティで、「測り忘れ」「書き忘れ」を防ぐ。
全体だけでなく、ステップごとの実行時間も測って、どこがボトルネックかを特定する。
どこを測るか、どの粒度でログに出すかを、性能とセキュリティの観点から設計する。

もし今、「なんとなく遅いけど、どこが遅いのか分からない」処理が頭に浮かんでいるなら、
そこにまず一つ、実行時間計測を差し込んでみてください。

数字が出た瞬間に、議論は感覚から事実に変わります。
それが、実務エンジニアとしての一歩先のステージに進むための、かなり確かな一歩になります。

スポンサーリンク
タイトルとURLをコピーしました