使用System.Diagnostics.Stopwatch对程序的运行时间精确地测量

简介:

介绍

    每个使用System.Diagnostics命名空间下的Stopwatch类做性能优化的人迟早会遇到一些麻烦。每个人都可以看到了,在同一台电脑相同功能的测试在运行时间上会有25% -30%不同。本文介绍如何使用Stopwatch类设计单线程测试程序获得0.1% - 0.2%准确性。有了这个精度,算法才可以进行测试和比较。

背景

    现代CPU有多个内核,大容量高速缓存,指令管道和许多其他的东西影响特定测试场景一个算法的运行时间。白盒测试技术-如附加的调试器或者分析器-关闭CPU的高速缓存线路,管道等。真正的运行时间是隐藏的,这样这些现代超标量处理器优化的计算方法执行速度要比使用分析器的没有优化的还要慢(由于更多的指令)。黑盒测试没有附加的调试器或分析器(运行时间测量),能发现算法的实际性能,并完成了算法的性能分析。
设置测试方案

    最重要的是防止CPU内核或处理器之间的切换。对性能测试有很大的影响。这可以通过设置进程的ProcessorAffinity来实现:

Process.GetCurrentProcess().ProcessorAffinity  =   new  IntPtr( 2 );  //  Use only the second core 

    为了能独占CPU内核,我们必须防止其他线程可以使用此CPU内核。我们设置进程和线程的优先级,来实现这一目标:

Process.GetCurrentProcess().PriorityClass  =  ProcessPriorityClass.High;
Thread.CurrentThread.Priority 
=  ThreadPriority.Highest;

    最后,但并非不重要的,在我们的测试需要热身阶段。在我的系统中,1000-1500毫秒热身阶段之后结果是稳定的。我们可以用stopwatch自己来控制热身(这里至少1200mS):

stopwatch.Start();
while  (stopwatch.ElapsedMilliseconds  <   1200 )
{
    result 
=  TestFunction(seed, count); 
}
stopwatch.Stop(); 

    下面是完整的示例:

复制代码
using  System;
using  System.Diagnostics;
using  System.Threading;

namespace  PreciseMeasure
{
    
class  Program
    {
        
static   void  Main( string [] args)
        {
            Stopwatch stopwatch 
=   new  Stopwatch();

            
long  seed  =  Environment.TickCount;      //  Prevents the JIT Compiler 
                    
//  from optimizing Fkt calls away
             long  result  =   0 ;
            
int  count  =   100000000 ;

            Console.WriteLine(
" 20 Tests without correct preparation " ); 
            Console.WriteLine(
" Warmup " );
            
for  ( int  repeat  =   0 ; repeat  <   20 ++ repeat)
            {
                stopwatch.Reset();
                stopwatch.Start();
                result 
^=  TestFunction(seed, count);
                stopwatch.Stop();
                Console.WriteLine(
" Ticks:  "   +  stopwatch.ElapsedTicks  +  
                
"  mS:  "   + stopwatch.ElapsedMilliseconds);
            }
            // Uses the second Core or Processor for the Test
            Process.GetCurrentProcess().ProcessorAffinity 
=   new  IntPtr( 2 ); 
            // Prevents "Normal" processes 
            // from interrupting Threads
            Process.GetCurrentProcess().PriorityClass  =  ProcessPriorityClass.High;     
            // Prevents "Normal" Threads 
            
Thread.CurrentThread.Priority  =  ThreadPriority.Highest;                          
            //  from interrupting this thread
            Console.WriteLine();
            Console.WriteLine();
            Console.WriteLine(
" 20 Tests with correct preparation " ); 
            Console.WriteLine(
" Warmup " );
            stopwatch.Reset();
            stopwatch.Start();
            
while  (stopwatch.ElapsedMilliseconds  <   1200 )   //  A Warmup of 1000-1500 mS 
                                                          
//  stabilizes the CPU cache and pipeline.
            {
                result 
=  TestFunction(seed, count);        //  Warmup
            }
            stopwatch.Stop();

            
for  ( int  repeat  =   0 ; repeat  <   20 ++ repeat)
            {
                stopwatch.Reset();
                stopwatch.Start();
                result 
^=  TestFunction(seed, count);
                stopwatch.Stop();
                Console.WriteLine(
" Ticks:  "   +  stopwatch.ElapsedTicks  +  
                
"  mS:  "   +  stopwatch.ElapsedMilliseconds);
            }
            Console.WriteLine(result); 
//  prevents optimizations (current compilers are 
        
//  too silly to analyze the dataflow that deep, but we never know )
        }

        
public   static   long  TestFunction( long  seed,  int  count)
        {
            
long  result  =  seed;
            
for  ( int  i  =   0 ; i  <  count;  ++ i)
            {
                result 
^=  i  ^  seed;  //  Some useless bit operations
            }
            
return  result;
        }
    }
}
复制代码

结果:

没有正确的准备

  1. Ticks: 1580367 mS: 572 <-- highest Value
  2. Ticks: 1577003 mS: 571
  3. Ticks: 1576140 mS: 571
  4. Ticks: 1560964 mS: 565
  5. Ticks: 1351663 mS: 489
  6. Ticks: 1248383 mS: 452
  7. Ticks: 1115361 mS: 404
  8. Ticks: 1112813 mS: 403
  9. Ticks: 1113112 mS: 403
  10. Ticks: 1112012 mS: 402 <-- lowest Value
  11. Ticks: 1330444 mS: 482
  12. Ticks: 1558493 mS: 564
  13. Ticks: 1501097 mS: 543
  14. Ticks: 1517796 mS: 549
  15. Ticks: 1542712 mS: 558
  16. Ticks: 1574959 mS: 570
  17. Ticks: 1483975 mS: 537
  18. Ticks: 1390578 mS: 503
  19. Ticks: 1546904 mS: 560
  20. Ticks: 1349507 mS: 488

运行时间在402ms572ms之间不等。存在170 mS 或者42%差距。很显然,这些结果是没有用的。

正确的准备:

  1. Ticks: 1110518 mS: 402
  2. Ticks: 1110540 mS: 402
  3. Ticks: 1110543 mS: 402
  4. Ticks: 1110684 mS: 402 <-- highest Value
  5. Ticks: 1110508 mS: 402
  6. Ticks: 1110553 mS: 402
  7. Ticks: 1110600 mS: 402
  8. Ticks: 1110433 mS: 402 <-- lowest Value
  9. Ticks: 1110509 mS: 402
  10. Ticks: 1110508 mS: 402
  11. Ticks: 1110489 mS: 402
  12. Ticks: 1110568 mS: 402
  13. Ticks: 1110503 mS: 402
  14. Ticks: 1110566 mS: 402
  15. Ticks: 1110625 mS: 402
  16. Ticks: 1110474 mS: 402
  17. Ticks: 1110571 mS: 402
  18. Ticks: 1110448 mS: 402
  19. Ticks: 1110555 mS: 402
  20. Ticks: 1110495 mS: 402

    有20个相同的结果:402 ms ,只能用tick(内部CPU性能计数器值)分辨。测试结果存在251tick或者0,02 %差距。在我的系统中,Stopwatch的频率是每秒2760029 tick。测试之间的运行差别只有0,09毫秒。这用于衡量和比较算法运行是非常好的。

兴趣点:

    其中一个很重要的事情应该牢记。没有做准备的最好(最低)结果值还没有做了准备的最差结果值好。CPU的上下文和核心交换对应用程序运行会产生巨大影响。

英文版:http://www.codeproject.com/KB/testing/stopwatch-measure-precise.aspx








本文转自麒麟博客园博客,原文链接:http://www.cnblogs.com/zhuqil/archive/2010/03/01/stopwatch-measure-precise.html,如需转载请自行联系原作者

相关文章
|
27天前
|
存储 算法 Linux
理解和使用 C++ 中的 `times` 函数:度量进程时间
理解和使用 C++ 中的 `times` 函数:度量进程时间
37 0
|
8月前
|
算法 Java 测试技术
精准计时工具:深入了解 Stopwatch(计时器)
在计算机编程领域中,精确计时是一个关键的需求,特别是在性能优化、算法分析等场景下。Stopwatch,作为一个用于测量时间间隔的工具,可以帮助开发者精确地计时代码的执行时间。在本文中,我们将详细介绍 Stopwatch 的特性、用法以及在实际应用中的优势。
352 0
|
11月前
|
算法 数据可视化
计算代码运行时间的 5 种方法
计算代码运行时间的 5 种方法
477 0
用StopWatch 统计代码耗时
用StopWatch 统计代码耗时
97 0
用StopWatch 统计代码耗时
|
Java
Java | 使用 StopWatch 优雅打印执行耗时
Java | 使用 StopWatch 优雅打印执行耗时
1069 0
|
小程序 Java Apache
别再用 System.currentTimeMillis() 统计耗时了,太 Low,StopWatch 好用到爆!
别再用 System.currentTimeMillis() 统计耗时了,太 Low,StopWatch 好用到爆!
187 0
别再用 System.currentTimeMillis() 统计耗时了,太 Low,StopWatch 好用到爆!
|
缓存 Java Linux
System.currentTimeMillis() 和 System.nanoTime() 哪个更快?别用错了!
System.currentTimeMillis() 和 System.nanoTime() 哪个更快?别用错了!
159 0
|
JavaScript Dubbo 小程序
还在用 System.currentTimeMillis() 统计代码耗时?太 Low 啦
还在用 System.currentTimeMillis() 统计代码耗时?太 Low 啦
|
Java Spring
统计代码耗时的工具 StopWatch
项目中通常会通过打印时间来查看某段任务的耗时,进行项目优化
629 0
|
Java Spring
别再用System.currentTimeMillis()!拥抱StopWatch优雅计算程序执行耗时
别再用System.currentTimeMillis()!拥抱StopWatch优雅计算程序执行耗时
126 0