C＃プロパティの値を文字列に連結するときの "奇妙な"ベンチマークの返信

Question

反射ベンチマークテストを試しましたが、ほとんど私は自分自身を混乱させました。両方のテストが合格する理由を誰かに説明できますか？私はそれが失敗する期待していた最初のもののために

が、私がいただ回：

millisecondsReflection - 4970ミリ秒

ミリ秒 - 6935ミリ秒

[Fact] 
    public void PropertiesGetterString() 
    { 
     var bar = new Bar 
     { 
      Id = 42, 
      Number = "42", 
     }; 

     string concat = string.Empty; 
     string concatReflection = string.Empty; 

     var props = bar.GetType().GetProperties(); 

     Stopwatch sw = new Stopwatch(); 
     sw.Start(); 

     for (int i = 0; i < 100000; i++) 
     { 
      concatReflection += props[1].GetValue(bar); 
     } 

     sw.Stop(); 

     long millisecondsReflection = sw.ElapsedMilliseconds; 

     sw.Reset(); 

     sw.Start(); 

     for (int i = 0; i < 100000; i++) 
     { 
      concat += bar.Number; 
     } 

     sw.Stop(); 

     long milliseconds = sw.ElapsedMilliseconds; 

     millisecondsReflection.Should().BeLessOrEqualTo(milliseconds); 
    } 

Iそれは文字列連結または型変換と関係があると考えて、それをリストに追加して追加し、予想される結果、すなわち反射を得ました遅かった。

[Fact] 
    public void PropertiesGetterArray() 
    { 
     var bar = new Bar 
     { 
      Id = 42, 
      Number = "42", 
     }; 

     List<object> concat = new List<object>(); 
     List<object> concatReflection = new List<object>(); 

     var props = bar.GetType().GetProperties(); 

     Stopwatch sw = new Stopwatch(); 
     sw.Start(); 

     for (int i = 0; i < 1000000; i++) 
     { 
      concatReflection.Add(props[1].GetValue(bar)); 
     } 

     sw.Stop(); 

     long millisecondsReflection = sw.ElapsedMilliseconds; 

     sw.Reset(); 
     sw.Start(); 

     for (int i = 0; i < 1000000; i++) 
     { 
      concat.Add(bar.Number); 
     } 

     sw.Stop(); 

     long milliseconds = sw.ElapsedMilliseconds; 

     millisecondsReflection.Should().BeGreaterOrEqualTo(milliseconds); 
    } 

は、ここでの結果は以下のとおりであった：

millisecondsReflection - 184ミリ秒

ミリ秒 - 11ミリ秒

私の質問は、私がここで何を逃していますか？

P.S.時間はデバッグモード中です。文字列の連結のオーバーヘッド、反射のオーバーヘッドを圧倒される：リリースモードでのコメントに示すように、時間が互いに

Answer 1

概要

この不一致は、2つのものを引き起こしているに非常に近いです;デバッグビルドが地元の人生を処理する方法の違いがあります。

リリースビルドとデバッグビルドの間に見られる時間の違いは、リリースビルドとは対照的に、デバッグビルドでメソッドが終了するまでローカルのビルドが維持されるためです。

これは、コード内の2つの文字列のGCが、リリースビルドとデバッグビルドの間で非常に異なった動作をする原因となっています。

詳細な分析は

あなただけの代わりに文字列プロパティの長さを合計するテストコードを変更する場合は、期待される結果を取得します。ここで

は私の結果（リリースビルド）です：

Trial 1 
Length = 20000000 
Length = 20000000 
Without reflection: 8 
With reflection: 1613 
Trial 2 
Length = 20000000 
Length = 20000000 
Without reflection: 8 
With reflection: 1606 
Trial 3 
Length = 20000000 
Length = 20000000 
Without reflection: 8 
With reflection: 1598 
Trial 4 
Length = 20000000 
Length = 20000000 
Without reflection: 8 
With reflection: 1609 
Trial 5 
Length = 20000000 
Length = 20000000 
Without reflection: 9 
With reflection: 1619 

とテストコード：

using System; 
using System.Diagnostics; 

namespace Demo 
{ 
    class Bar 
    { 
     public int Id { get; set; } 
     public string Number { get; set; } 
    } 

    static class Program 
    { 
     static void Main() 
     { 
      for (int trial = 1; trial <= 5; ++trial) 
      { 
       Console.WriteLine("Trial " + trial); 
       PropertiesGetterString(); 
      } 
     } 

     public static void PropertiesGetterString() 
     { 
      int count = 10000000; 

      var bar = new Bar 
      { 
       Id = 42, 
       Number = "42", 
      }; 

      int totalLength = 0; 

      var props = bar.GetType().GetProperties(); 

      Stopwatch sw = new Stopwatch(); 
      sw.Start(); 

      for (int i = 0; i < count; i++) 
      { 
       totalLength += ((string)props[1].GetValue(bar)).Length; 
      } 

      sw.Stop(); 
      long millisecondsReflection = sw.ElapsedMilliseconds; 
      Console.WriteLine("Length = " + totalLength); 

      sw.Reset(); 
      totalLength = 0; 
      sw.Start(); 

      for (int i = 0; i < count; i++) 
      { 
       totalLength += bar.Number.Length; 
      } 

      sw.Stop(); 
      long milliseconds = sw.ElapsedMilliseconds; 
      Console.WriteLine("Length = " + totalLength); 

      Console.WriteLine("Without reflection: " + milliseconds); 
      Console.WriteLine("With reflection: " + millisecondsReflection); 
     } 
    } 
} 

はまた、私は唯一のデバッグビルドではなく、リリースビルドを使用して、元の結果を再現することができますことに注意してください。

私はあなたのOPごとに文字列連結を行うには、私のテストコードを変更した場合、私はこれらの結果を得る：

最後に

Trial 1 
Without reflection: 3686 
With reflection: 3661 
Trial 2 
Without reflection: 3584 
With reflection: 3688 
Trial 3 
Without reflection: 3587 
With reflection: 3676 
Trial 4 
Without reflection: 3550 
With reflection: 3700 
Trial 5 
Without reflection: 3564 
With reflection: 3659 

、二つのループ上のバックグラウンドGCの影響を最小限にするために更なる試みとして、私は、

GC.Collect(); 
GC.WaitForPendingFinalizers(); 

に結果を変更：

Trial 1 
Without reflection: 3565 
With reflection: 3665 
Trial 2 
Without reflection: 3538 
With reflection: 3631 
Trial 3 
Without reflection: 3535 
With reflection: 3597 
Trial 4 
Without reflection: 3558 
With reflection: 3629 
Trial 5 
Without reflection: 3551 
With reflection: 3599 

への各呼び出しの後に次のコードを追加しました

この変更では、「反射あり」の結果はすべて「反射なし」の結果よりも遅くなります。

最後に、デバッグモードで観察された違いを調べてみましょう。

ループの順序のために違いが発生しているように見えます。ダイレクトループの前にリフレクションループを使用して1つのテストを試すと、その逆の結果が得られます。

は、ここに私の最後のテストプログラムの結果です：どちらループが最初に実行されていることを

Trial 1 
PropertiesGetterStringWithoutThenWithReflection() 
Without reflection: 3228 
With reflection: 5866 
PropertiesGetterStringWithThenWithoutReflection() 
Without reflection: 5780 
With reflection: 3273 
Trial 2 
PropertiesGetterStringWithoutThenWithReflection() 
Without reflection: 3207 
With reflection: 5921 
PropertiesGetterStringWithThenWithoutReflection() 
Without reflection: 5802 
With reflection: 3318 
Trial 3 
PropertiesGetterStringWithoutThenWithReflection() 
Without reflection: 3246 
With reflection: 5873 
PropertiesGetterStringWithThenWithoutReflection() 
Without reflection: 5882 
With reflection: 3297 
Trial 4 
PropertiesGetterStringWithoutThenWithReflection() 
Without reflection: 3261 
With reflection: 5891 
PropertiesGetterStringWithThenWithoutReflection() 
Without reflection: 5778 
With reflection: 3298 
Trial 5 
PropertiesGetterStringWithoutThenWithReflection() 
Without reflection: 3267 
With reflection: 5948 
PropertiesGetterStringWithThenWithoutReflection() 
Without reflection: 5830 
With reflection: 3306 

注意かかわらず、それが反射をやっているかどうかの、最速です。これは、その違いが、デバッグビルドで文字列の処理が行われている方法のアーティファクトであることを意味します。

私は、デバッグビルドでは、メソッド全体に対して連結された文字列が生きているのに対し、リリースビルドではGCに影響すると考えられます。

は、ここで上記の結果のためのテストコードです：

using System; 
using System.Diagnostics; 

namespace Demo 
{ 
    class Bar 
    { 
     public int Id { get; set; } 
     public string Number { get; set; } 
    } 

    static class Program 
    { 
     static void Main() 
     { 
      for (int trial = 1; trial <= 5; ++trial) 
      { 
       Console.WriteLine("Trial " + trial); 
       PropertiesGetterStringWithoutThenWithReflection(); 
       PropertiesGetterStringWithThenWithoutReflection(); 
      } 
     } 

     public static void PropertiesGetterStringWithoutThenWithReflection() 
     { 
      Console.WriteLine("PropertiesGetterStringWithoutThenWithReflection()"); 

      int count = 100000; 

      var bar = new Bar 
      { 
       Id = 42, 
       Number = "42", 
      }; 

      var props = bar.GetType().GetProperties(); 
      string concat1 = ""; 
      string concat2 = ""; 

      Stopwatch sw = new Stopwatch(); 
      sw.Start(); 

      for (int i = 0; i < count; i++) 
      { 
       concat2 += bar.Number; 
      } 

      sw.Stop(); 
      GC.Collect(); 
      GC.WaitForPendingFinalizers(); 
      long milliseconds = sw.ElapsedMilliseconds; 
      sw.Restart(); 

      for (int i = 0; i < count; i++) 
      { 
       concat1 += (string)props[1].GetValue(bar); 
      } 

      sw.Stop(); 
      GC.Collect(); 
      GC.WaitForPendingFinalizers(); 
      long millisecondsReflection = sw.ElapsedMilliseconds; 

      Console.WriteLine("Without reflection: " + milliseconds); 
      Console.WriteLine("With reflection: " + millisecondsReflection); 
     } 

     public static void PropertiesGetterStringWithThenWithoutReflection() 
     { 
      Console.WriteLine("PropertiesGetterStringWithThenWithoutReflection()"); 

      int count = 100000; 

      var bar = new Bar 
      { 
       Id = 42, 
       Number = "42", 
      }; 

      var props = bar.GetType().GetProperties(); 
      string concat1 = ""; 
      string concat2 = ""; 

      Stopwatch sw = new Stopwatch(); 
      sw.Start(); 

      for (int i = 0; i < count; i++) 
      { 
       concat1 += (string)props[1].GetValue(bar); 
      } 

      sw.Stop(); 
      GC.Collect(); 
      GC.WaitForPendingFinalizers(); 
      long millisecondsReflection = sw.ElapsedMilliseconds; 
      sw.Restart(); 

      for (int i = 0; i < count; i++) 
      { 
       concat2 += bar.Number; 
      } 

      sw.Stop(); 
      GC.Collect(); 
      GC.WaitForPendingFinalizers(); 
      long milliseconds = sw.ElapsedMilliseconds; 

      Console.WriteLine("Without reflection: " + milliseconds); 
      Console.WriteLine("With reflection: " + millisecondsReflection); 
     } 
    } 
} 

---

UPDATE

私もリリースビルドの違いを再現しました。私はこれが、私が疑っているように、その違いは文字列がどれくらい長く生きているかによると証明していると思います。

ここでリリースビルドとして実行されるテストコード、です：どのように最初のループ

Trial 1 
Without reflection: 4957 
With reflection: 3646 
400000 
Trial 2 
Without reflection: 4941 
With reflection: 3626 
400000 
Trial 3 
Without reflection: 4969 
With reflection: 3609 
400000 
Trial 4 
Without reflection: 5021 
With reflection: 3690 
400000 
Trial 5 
Without reflection: 4769 
With reflection: 3637 
400000 

注：私は-あるとして、私は次のような結果を得ることを実行する場合

public static void PropertiesGetterString() 
{ 
    int count = 100000; 

    var bar = new Bar 
    { 
     Id = 42, 
     Number = "42", 
    }; 

    var props = bar.GetType().GetProperties(); 
    string concat1 = ""; 
    string concat2 = ""; 

    Stopwatch sw = new Stopwatch(); 
    sw.Start(); 

    for (int i = 0; i < count; i++) 
    { 
     concat1 += (string)props[1].GetValue(bar); 
    } 

    sw.Stop(); 
    GC.Collect(); 
    GC.WaitForPendingFinalizers(); 
    long millisecondsReflection = sw.ElapsedMilliseconds; 
    sw.Restart(); 

    for (int i = 0; i < count; i++) 
    { 
     concat2 += bar.Number; 
    } 

    sw.Stop(); 
    GC.Collect(); 
    GC.WaitForPendingFinalizers(); 
    long milliseconds = sw.ElapsedMilliseconds; 

    Console.WriteLine("Without reflection: " + milliseconds); 
    Console.WriteLine("With reflection: " + millisecondsReflection); 
    Console.WriteLine(concat1.Length + concat2.Length); // Try with and without this line commented out. 
} 

（反射あり）は第2の反射よりも速い（反射なし）。

メソッドの最後の行（2つの文字列の長さを出力する行）をコメント化してもう一度実行します。今回の結果は以下のとおりです。

Trial 1 
Without reflection: 3558 
With reflection: 3690 
Trial 2 
Without reflection: 3653 
With reflection: 3624 
Trial 3 
Without reflection: 3606 
With reflection: 3663 
Trial 4 
Without reflection: 3592 
With reflection: 3660 
Trial 5 
Without reflection: 3629 
With reflection: 3644 

これは、私が思うに、デバッグとリリースビルド時間の差は、デバッグビルドは、（メソッドの最後まで生きているすべての地元の人々を保つという事実によるものであることを証明していますメソッド内で最後に使用していたとしてもデバッガに表示されるようにします）。

対照的に、リリースビルドでは、最後にメソッドで使用した後にいつでも参照をGCできます。