java.util.regexとString.substringの性能の違いはどれだけか

正規表現（java.uitl.regexパッケージ）を使った文字列切り出しと、Stringクラスのsubstringによる文字列切り出しとで性能比較をすると、感覚的には正規表現がかなり遅いと思っていました。
この２つの実行時間を測定して比べてみました。

背景

周期的に送られてくるデータを処理するようなコードでは、一つ一つの処理は短くても、積み上がってみると処理が追いつかずパンクするということがあります。

例えば、通信レコード1件に10種類のデータ項目が含まれ、1データ項目の受信処理に100usかかるとします。ここでデータ項目とは、日時、店コード、品名コード、などです。受信処理は通信フォーマット（ある規則の文字列、バイナリ）をプログラムで扱うデータ型に変換するようなものです。

1秒間に通信レコード1000件の要求が発生すると、受信処理時間は、1000*10*100usで1秒となります。受信処理だけ見れば要求にぴったり収まりますが、余裕率が皆無なので、受信以外の処理（受信の後段の処理に渡す時間、ログ出力時間、GCでストップされる時間、OSのスレッドスケジューリングでプリエンプトされる時間、受信データのエラー処理時間、など）が発生した時点で1秒を越えてしまいます。そうなると、それ以降着信するデータの処理が遅れ、余裕率がないので挽回の余地がなく、バッファ（アプリケーション・OS・TCPなどのバッファ）が溢れ、送信側が滞り、などシステム全体に連鎖的に悪影響が及びます。

ちょっと話がずれてしまいましたが、まずは周期に収まるように100usの処理を工夫して周期に間に合うようにします。それにもいろいろなやり方がありますが（データのレコード間に依存関係がなければ並列化する等）、ここはまず逐次処理での性能を追求します。

実行性能のボトルネックを探すので、通常はプロファイラ・ツールでCPUプロファイリングを取って解析するのが常套です。しかし、サンプリングのものは分解能が1〜10msとなるので、100usの中を切り分けたいときには適用が難しいと思われ、実行時間でとるものはオーバーヘッドが大きくこれも難しいと思われます。

測定方法

べたなやり方として、プログラムのコードを部分区間ごとにタイムスタンプを取っていく方法をとります。コードイメージは次のようなものになります。

public void method() {
  long start = System.nanoTime();
  // ... 区間1
  long lap1 = System.nanoTime();
  // ... 区間2
  long lap2 = System.nanoTime();
  :
}

これは「マイクロベンチマーク」として、要注意な測定方法となります。
Javaのマイクロベンチマークに関する技術的な検討（問題点）は、IBM developerworksの記事などで詳しく説明されています。

2番目の記事では、マイクロベンチマークにおける問題を考慮したベンチマークフレームワークを紹介しています。これを利用するとよさそうですが、まずは自分の手で問題が起きるコードを書いて試して、そこから身をもって学ぶこととします。

測定

まず、日時文字列（2011-12-11 00:58:21）から年月日時分秒を各整数型に変換する処理があり、それがボトルネックかどうかを見るため計測する、というシナリオでベンチマークを作ることにします。

日付処理のコードイメージを以下に示します。

public class TimeStamp {
    private static Pattern pattern = Pattern.compile("(\\d{4})-(\\d{2})-(\\d{2}) (\\d{2}):(\\d{2}):(\\d{2})");
    private int year;
    private int month;
    // ...
    void parse(String text) {
        Matcher matcher = pattern.matcher(text);
        if (matcher.matches()) {
            year = Integer.parseInt(matcher.group(1));
            month = Integer.parseInt(matcher.group(2));
            // ...
         }
    }
    // ...
}

正規表現は「遅い」というイメージもあり、固定長フォーマットなのだからここはString.substringで切り出した方がよいと思います。
そこで、regexを使った場合とsubstringを使った場合を比較するため、JUnitに（安直な）コードを書いて実行します。

@Test public void 実行時間を測定() {
    long start = System.nanoTime();
    timestamp.parse("2011-12-11 01:08:14");
    long stop = System.nanoTime();
    System.out.printf("parse: %d [ns]%n", stop - start);
}

この結果は、parse: 82133 [ns] と出ました。
（Windows 7/JDK7 u1、CPU: AMD PhenomII 1055T）

Javaに限らず、C++でも最初の1回目の関数呼び出しは（特に共有ライブラリの関数呼び出しなど）通常遅いものになります。Javaの場合は、さらにHotSpotコンパイラによるネイティブコードへのコンパイルがされるまでは遅い値となります。

そこで、計測前にあらかじめ繰り返しparseメソッドを呼ぶコードを入れます。
コードイメージは以下となります。

@Test public void 暖気運転後実行時間を測定() {
    for (int i=0; i<1500; i++)
        timestamp.parse("2011-12-11 01:55");
    long start = System.nanoTime();
    timestamp.parse("2011-12-11 01:08:14");
    long stop = System.nanoTime();
    System.out.printf("parse: %d [ns]%n", stop - start);
}

この結果は、parse: 8800 [ns]　と出ました。
ここで、1500回ループしているのは、HotSpotVM（クライアントVM）の-XX:CompileThresholdのデフォルトが1500と以下の記事にあったからです。

http://java.sun.com/docs/books/performance/1st_edition/html/JPAppHotspot.fm.html

次に、String.substringで日時文字列をパースする処理を書いて測定してみたところ、
暖気運転なしでは、26400 [ns]、暖気運転1500回では、3422 [ns] となりました。

ここで、8800nsと3422nsの数値を比べるのは危険です。このオーダーになると、そもそもSystem.nanoTime()の取得がマイクロ秒かかるといわれており、測定分解能ぎりぎりの測定値となっています。また、繰り返し測定してみたところ、値のばらつきが大きかったので、統計的に処理してみる必要があります。

今回は統計処理までたどり着けていませんが、正規表現がさほど遅くないということが分かり、今までの直観的な感覚であった正規表現は重い、という認識を改める必要があるなと感じました。

torutkのブログ

ソフトウェア・エンジニアのブログ

java.util.regexとString.substringの性能の違いはどれだけか

背景

測定方法

測定