2014-10-20 106 views
4

我試圖測量線程中用於進度報告目的的時間,但是我從GetThreadTimes系統調用中得到了非常奇怪的結果。考慮下面的程序(在VS 2013編譯,針對.NET 4.5):GetThreadTimes爲什麼返回

using System; 
using System.Diagnostics; 
using System.Runtime.InteropServices; 
using System.Threading; 

namespace ThreadTimingTest 
{ 
    class Program 
    { 
     static Stopwatch _wallClockTimer; 

     static System.Timers.Timer _timer = new System.Timers.Timer(); 

     private static Thread _thread; 
     private static IntPtr _threadHandle; 

     static void Main(string[] args) 
     { 
      _timer = new System.Timers.Timer(); 
      _timer.Elapsed += (s, e) => 
      { 
       System.Runtime.InteropServices.ComTypes.FILETIME start, end, rawKernelTime, rawUserTime; 

       GetThreadTimes(_threadHandle, out start, out end, out rawKernelTime, out rawUserTime); 

       //ref: http://stackoverflow.com/a/6083846 
       ulong uLow = (ulong)rawKernelTime.dwLowDateTime; 
       ulong uHigh = (uint)rawKernelTime.dwHighDateTime; 
       uHigh = uHigh << 32; 
       long kernelTime = (long)(uHigh | uLow); 

       uLow = (ulong)rawUserTime.dwLowDateTime; 
       uHigh = (uint)rawUserTime.dwHighDateTime; 
       uHigh = uHigh << 32; 
       long userTime = (long)(uHigh | uLow); 

       Debug.WriteLine("Kernel time: " + kernelTime); 
       Debug.WriteLine("User time: " + userTime); 
       Debug.WriteLine("Combined raw execution time: " + (kernelTime + userTime)); 

       long elapsedMilliseconds = (kernelTime + userTime)/10000; //convert to milliseconds: raw timing unit is 100 nanoseconds 
       Debug.WriteLine("Elapsed thread time: " + elapsedMilliseconds + " milliseconds"); 

       Debug.WriteLine("Wall Clock Time: " + _wallClockTimer.ElapsedMilliseconds + " milliseconds"); 

      }; 

      _timer.Interval = 1000; 

      _wallClockTimer = new Stopwatch(); 

      Debug.WriteLine("Starting..."); 
      RunTest(); 

      Debug.WriteLine("Ended."); 
     } 

     public static void RunTest() 
     { 
      _thread = 
       new Thread 
       (
        () => 
        { 
         _threadHandle = GetCurrentThread(); 
         Stopwatch sw = Stopwatch.StartNew(); 

         while (sw.ElapsedMilliseconds < 3000) 
         { 
          int i = 1 + 2; 
         } //do busy-work for 3 seconds 

         sw.Stop(); 
        } 
       ); 

      _timer.Start(); 

      _thread.Start();a 

      _wallClockTimer.Start(); 

      _thread.Join(); 
     } 

     [DllImport("kernel32.dll", SetLastError = true)] 
     static extern bool GetThreadTimes(IntPtr hThread, 
      out System.Runtime.InteropServices.ComTypes.FILETIME lpCreationTime, out System.Runtime.InteropServices.ComTypes.FILETIME lpExitTime, 
      out System.Runtime.InteropServices.ComTypes.FILETIME lpKernelTime, out System.Runtime.InteropServices.ComTypes.FILETIME lpUserTime); 

     [DllImport("kernel32.dll")] 
     private static extern IntPtr GetCurrentThread(); 
    } 
} 

我得到以下輸出:

Starting... 
Kernel time: 0 
User time: 0 
Combined raw execution time: 0 
Elapsed thread time: 0 milliseconds 
Wall Clock Time: 1036 milliseconds 
Kernel time: 0 
User time: 0 
Combined raw execution time: 0 
Elapsed thread time: 0 milliseconds 
Wall Clock Time: 2036 milliseconds 
The thread '<No Name>' (0x191c) has exited with code 0 (0x0). 
Ended. 

我希望GetThreadTimes爲螺紋次報告爲零以外的東西:爲什麼零報告?

+1

[多個託管線程可以在同一個操作系統線程上運行](http://msdn.microsoft.com/en-us/library/74169f59.aspx)。假設:.NET運行時在完成其時間片之前正在中斷OS線程,因此其時間不會被記錄(參見[this](http://blog.kalmbachnet.de/?postid=28)文章)。當然,時間不會準確無論如何,因爲你沒有測量在* managed *線程中花費的時間,你正在測量底層的OS線程。 – Blorgbeard 2014-10-20 19:31:41

+4

因爲GetCurrentThread()不會返回您認爲它的作用。讓你衡量錯誤線程的時間。剛剛在[此博客文章]中報道(http://blogs.msdn.com/b/oldnewthing/archive/2014/10/15/10564700.aspx)。 – 2014-10-20 19:48:28

回答

3

在根據Hans提供的鏈接對代碼進行幾個簡單的修改後,將顯示有效時間。

添加幾個互操作的聲明:

[DllImport("kernel32.dll", SetLastError = true)] 
[return: MarshalAs(UnmanagedType.Bool)] 
static extern bool DuplicateHandle(IntPtr hSourceProcessHandle, 
    IntPtr hSourceHandle, IntPtr hTargetProcessHandle, out IntPtr lpTargetHandle, 
    uint dwDesiredAccess, [MarshalAs(UnmanagedType.Bool)] bool bInheritHandle, uint dwOptions); 

[Flags] 
public enum DuplicateOptions : uint 
{ 
    DUPLICATE_CLOSE_SOURCE = (0x00000001), // Closes the source handle. This occurs regardless of any error status returned. 
    DUPLICATE_SAME_ACCESS = (0x00000002), // Ignores the dwDesiredAccess parameter. The duplicate handle has the same access as the source handle. 
} 

[DllImport("kernel32.dll")] 
static extern IntPtr GetCurrentProcess(); 

然後修改手柄如何分配:

//_threadHandle = GetCurrentThread();  <-- previous assignment 
IntPtr processHandle = GetCurrentProcess(); 
bool result = DuplicateHandle(processHandle, GetCurrentThread(), processHandle, out _threadHandle, 0, false, (uint) DuplicateOptions.DUPLICATE_SAME_ACCESS); 

產生以下結果:

Starting... 
Kernel time: 0 
User time: 10000000 
Combined raw execution time: 10000000 
Elapsed thread time: 1000 milliseconds 
Wall Clock Time: 1006 milliseconds 
Kernel time: 0 
User time: 20000000 
Combined raw execution time: 20000000 
Elapsed thread time: 2000 milliseconds 
Wall Clock Time: 2004 milliseconds 
Kernel time: 0 
User time: 30000000 
Combined raw execution time: 30000000 
Ended. 
Elapsed thread time: 3000 milliseconds 
Wall Clock Time: 3045 milliseconds 

編輯:

最近,我們付出了很大的努力來處理爲給定系統創建的太多線程。假設你有一個四核處理器,並且有20多個線程都想運行。線程在啓動,內核管理,內存(他們有自己的堆棧)等方面的成本相當高。與減少線程數量相比,系統實際上可能更慢(雜亂的上下文和調度)。所以在.NET中,創建了類似TPL的庫(允許開發人員管理任務,而不是線程)。這使得CLR能夠將適當的線程數量平衡到目標系統。但在你的情況下(你明確地創建一個託管線程),與本地線程幾乎總是有1對1的關係。

希望這會有所幫助。

+0

感謝您的回答!但我不清楚一件事:這個解決方案如何解決@ Blorgbeard的觀察:多個託管線程可以在同一個OS線程上運行? – Caleb 2014-10-22 17:59:43

+0

@Caleb - 我會編輯我的答案(因爲解釋有點長)。 – Jeff 2014-10-22 19:18:00