Почему GetThreadTimes возвращается

Question

Я пытаюсь измерить время, проведенное в потоке, для целей отчета о проделанной работе, но я получаю очень странные результаты из системного вызова GetThreadTimes. Учитывая следующую программу (скомпилированную в VS 2013, таргетирования .NET 4.5):

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, чтобы сообщить что-то, отличное от нуля в течение времени резьбы : почему ноль сообщается?

Answer 1

После создания пары простых модов для вашего кода на основе ссылки, предоставленной Хансом, отображаются действительные временные данные.

Добавление нескольких деклараций Interop:

[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 

EDIT:

В последнее время большое внимание было уделено обработке слишком большого количества потоков, созданных для данной системы. Допустим, у вас есть процессор с четырьмя процессорами, и 20+ потоков все хотят запускать. Потоки имеют довольно большие затраты на запуск, управление ядрами, память (у них есть собственный стек) и т. Д. Система может быть медленнее (жонглирование контекстов и планирование), чем если бы количество потоков было уменьшено. Итак, в .NET были созданы библиотеки типа TPL (позволяющие разработчику управлять задачами, а не потоками). Это позволяет CLR балансировать соответствующее количество потоков в целевой системе. Но в вашем случае (где вы явно создаете управляемый поток) почти всегда существует отношение 1 к 1 с собственными потоками.

Надеюсь, это поможет.