VisualVM - 奇妙な自己時間

Question

今日私はVisual VMのプロファイリングの結果に混乱しました。

public class Encoder { 
    ... 
    private BitString encode(InputStream in, Map<Character, BitString> table) 
     throws IOException { 

    BufferedReader reader = new BufferedReader(new InputStreamReader(in)); 

    BitString result = new BitString(); 
    int i; 
    while ((i = reader.read()) != -1) { 
     char ch = (char) i; 
     BitString string = table.get(ch); 
     result = result.append(string); 
    } 

    return result; 
    } 
} 

このメソッドは、ストリームから文字を読み込み、一度に1：

は、私は次のような単純なJavaメソッドを持っています。各文字について、それはビット列表現を参照し、これらのビット列を結合してストリーム全体を表現します。

BitStringは、基本となるバイト配列を使用して一連のビットを表すカスタムデータ構造です。

このメソッドはパフォーマンスが非常に悪いです。問題はBitString#appendにあります。そのメソッドは新しいバイト配列を作成し、両方の入力BitStringからビットをコピーし、新しいBitStringインスタンスとして返します。私は何が起こっているかを確認するためにVisualVMのを使用しようとしたとき

public BitString append(BitString other) { 

    BitString result = new BitString(size + other.size); 
    int pos = 0; 

    for (byte b : this) { 
    result.set(pos, b); 
    pos++; 
    } 
    for (byte b : other) { 
    result.set(pos, b); 
    pos++; 
    } 

    return result; 
} 

しかし、ここで私が得たものです：

私は、一般的にはほとんどのVisual VMの経験とプロファイリングを持っています。私の理解では、これはencodeメソッド自体のどこかに嘘をついたかのように見えますが、appendにはありません。

確かに、私はこのように、計測カスタムタイムで全体のエンコード方法とアペンドコールを囲ん：

public class Encoder { 
    private BitString encode(InputStream in, Map<Character, BitString> table) 
     throws IOException { 

>> long startTime = System.currentTimeMillis(); 
>> long appendDuration = 0; 

    BufferedReader reader = new BufferedReader(new InputStreamReader(in)); 

    BitString result = new BitString(); 
    int i; 
>> long count = 0; 
    while ((i = reader.read()) != -1) { 
     char ch = (char) i; 
     BitString string = table.get(ch); 

>> long appendStartTime = System.currentTimeMillis(); 
     result = result.append(string); 
>> long appendEndTime = System.currentTimeMillis(); 
>> appendDuration += appendEndTime - appendStartTime; 

>> count++; 
>> if (count % 1000 == 0) { 
>>  log.info(">>> CHARACTERS PROCESSED: " + count); 
>>  long endTime = System.currentTimeMillis(); 
>>  log.info(">>> TOTAL ENCODE DURATION: " + (endTime - startTime) + " ms"); 
>>  log.info(">>> TOTAL APPEND DURATION: " + appendDuration + " ms"); 
>> } 
    } 

    return result; 
    } 
} 

そして、私は次の結果得た：これは中にいるようだ

CHARACTERS PROCESSED: 102000 
TOTAL ENCODE DURATION: 188276 ms 
APPEND CALL DURATION: 188179 ms 

をVisual VMの結果と矛盾します。

私には何が欠けていますか？

Answer 1

[この回答は無効です。この投稿には他の人が問題を理解するのに役立つ2つのコメントが含まれているので、OPからメンバーの助けを借りるまでそれを保ちます。

この場合、VisualVMは実際のCPU時間を測定しましたが、測定した時間値は「経過時間」です。

実行スレッドがIOまたはネットワークを待たなければならない場合、その時間はCPU時間として測定されません。