2016-05-04 29 views
1

我試圖做一些反思基準測試的屬性值,但主要是我設法迷惑自己。可以請某人解釋爲什麼兩個測試都通過了C#反射「奇怪」的基準串聯時,字符串

這是第一個,我希望它失敗了,但我是時代:

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); 
    } 

我想通這是值得做的字符串連接或類型轉換,所以我改成了一個列表追加,並獲得了預期的效果,即反射速度較慢。

[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.在調試模式下進行的時間。如在釋放模式的註釋示出的時間非常接近彼此

+0

你用StringBuilder得到的結果是 – Prix

+0

你對GC產生了很大的壓力,如果GC在第二個迴路中間啓動,由於第一個迴路施加的所有壓力,該怎麼辦? –

+0

@ LasseV.Karlsen切換循環位置不會改變結果 – gyosifov

回答

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上的兩個循環的影響,我添加每次通話後下面的代碼sw.Stop()

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 

隨着這種變化,所有「帶反射」結果比「無反射」結果慢,正如您所期望的那樣。

最後,讓我們來看看在調試模式下觀察到的差異。

由於循環的順序,會出現差異。如果您在直接循環之前嘗試使用反射循環進行一次測試,則反之亦然。

這是我最後的測試程序的結果:

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

我轉載發佈版本的差別太大。我認爲這證明,正如我所懷疑的那樣,不同之處在於琴絃的存活時間有多長。

這裏的測試代碼,要運行一個發佈版本:

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. 
} 

如果我運行的原樣,我得到如下結果:

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 

注意如何第一個循環(有反射)比第二個(沒有反射)快。

現在註釋掉方法的最後一行(輸出兩個字符串長度的行)並再次運行。這一次的結果是:

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上次在方法中使用後的任何時候引用它。

+0

'也注意到我無法重現您的原始結果'我通過在調試模式下運行代碼 –

+3

但我們不應該在調試模式下比較性能。經過訓練的例子會給你帶來臆造的結果。請不要這樣做! –

+0

雖然這證明在釋放的時代是接近的,我仍然不明白爲什麼在調試的時代差異有利於反思.. – gyosifov