dotnet下时间精度测量-阿里云开发者社区

开发者社区> 云计算> 正文

dotnet下时间精度测量

简介:
在《dotnet程序优化心得》一文中我主要采用DateTime.Now.Ticks来测量时间,文中我说DateTime.Now.Ticks能够得到精确的时间,Ninputer指出这是一个错误的说法,DateTime.Now测不准ms级时间。我测试了一下,结果确实如此。测试代码如下:

 1None.gif
 2None.gifstatic void Main(string[] args) 
 3ExpandedBlockStart.gif
 4InBlock.gif    long start,end; 
 5InBlock.gif
 6InBlock.gif    start = DateTime.Now.Ticks; 
 7InBlock.gif    end = DateTime.Now.Ticks; 
 8InBlock.gif
 9InBlock.gif    while(start==end) 
10ExpandedSubBlockStart.gif    
11InBlock.gif        end = DateTime.Now.Ticks; 
12ExpandedSubBlockEnd.gif    }
 
13InBlock.gif
14InBlock.gif    Console.WriteLine("DateTime.Now.Ticks时间精度:{0}ms",(end-start)/10000); 
15ExpandedBlockEnd.gif}

16None.gif

运行结果:DateTime.Now.Ticks时间精度:10ms

yinh找到了一个程序QueryPerfCounter,可以进行精确的时间测量。代码如下:

 1None.gifusing System; 
 2None.gifusing System.ComponentModel; 
 3None.gifusing System.Runtime.InteropServices; 
 4None.gif
 5None.gifpublic class QueryPerfCounter 
 6ExpandedBlockStart.gif
 7InBlock.gif    [DllImport("KERNEL32")] 
 8InBlock.gif    private static extern bool QueryPerformanceCounter( 
 9InBlock.gif        out long lpPerformanceCount); 
10InBlock.gif
11InBlock.gif    [DllImport("Kernel32.dll")] 
12InBlock.gif    private static extern bool QueryPerformanceFrequency(out long lpFrequency); 
13InBlock.gif
14InBlock.gif    private long start; 
15InBlock.gif    private long stop; 
16InBlock.gif    private long frequency; 
17InBlock.gif    Decimal multiplier = new Decimal(1.0e9); 
18InBlock.gif
19InBlock.gif    public QueryPerfCounter() 
20ExpandedSubBlockStart.gif    
21InBlock.gif        if (QueryPerformanceFrequency(out frequency) == false
22ExpandedSubBlockStart.gif        
23InBlock.gif            // Frequency not supported 
24InBlock.gif            throw new Win32Exception(); 
25ExpandedSubBlockEnd.gif        }
 
26ExpandedSubBlockEnd.gif    }
 
27InBlock.gif
28InBlock.gif    public void Start() 
29ExpandedSubBlockStart.gif    
30InBlock.gif        QueryPerformanceCounter(out start); 
31ExpandedSubBlockEnd.gif    }
 
32InBlock.gif
33InBlock.gif    public void Stop() 
34ExpandedSubBlockStart.gif    
35InBlock.gif        QueryPerformanceCounter(out stop); 
36ExpandedSubBlockEnd.gif    }
 
37InBlock.gif
38InBlock.gif    public double Duration(int iterations) 
39ExpandedSubBlockStart.gif    
40InBlock.gif        return ((((double)(stop - start)* (double) multiplier) / (double) frequency)/iterations); 
41ExpandedSubBlockEnd.gif    }
 
42ExpandedBlockEnd.gif}

43None.gif


  我搜了一下,该程序原出处应该是http://channel9.msdn.com/wiki/default.aspx/PerformanceWiki.HowToTimeManagedCode

采用以下代码测试其时间精度:

1None.gifstatic void Main(string[] args) 
2ExpandedBlockStart.gif
3InBlock.gif    QueryPerfCounter q = new QueryPerfCounter(); 
4InBlock.gif
5InBlock.gif    q.Start(); 
6InBlock.gif    q.Stop(); 
7InBlock.gif
8InBlock.gif    Console.WriteLine("QueryPerfCounter时间精度:{0}ns",q.Duration(1)); 
9ExpandedBlockEnd.gif}

结果:

QueryPerfCounter时间精度:3911.1116077602ns

如果测试之前这么来一下:

// Call the object and methods to JIT before the test run 
QueryPerfCounter myTimer = new QueryPerfCounter(); 
myTimer.Start(); 
myTimer.Stop();

结果大概是1微妙。

也就是说QueryPerfCounter的测试精度是1微妙,这主要是因为方法调用和执行要花去一些时间。为了得到更精确的时间测量,必须对此进行时间校准,扣除方法调用和执行的时间.我在构造函数里面加了校准项。完整代码如下:

 1None.gifusing System;
 2None.gifusing System.ComponentModel; 
 3None.gifusing System.Runtime.InteropServices;
 4None.gif
 5None.gif    public class QueryPerfCounter 
 6ExpandedBlockStart.gif    
 7InBlock.gif        [DllImport("KERNEL32")] 
 8InBlock.gif        private static extern bool QueryPerformanceCounter( 
 9InBlock.gif            out long lpPerformanceCount); 
10InBlock.gif
11InBlock.gif        [DllImport("Kernel32.dll")] 
12InBlock.gif        private static extern bool QueryPerformanceFrequency(out long lpFrequency); 
13InBlock.gif        
14InBlock.gif        private long check;
15InBlock.gif        private long start; 
16InBlock.gif        private long stop; 
17InBlock.gif        private long frequency; 
18InBlock.gif        Decimal multiplier = new Decimal(1.0e9); 
19InBlock.gif
20InBlock.gif        public QueryPerfCounter() 
21ExpandedSubBlockStart.gif        
22InBlock.gif            if (QueryPerformanceFrequency(out frequency) == false
23ExpandedSubBlockStart.gif            
24InBlock.gif                // Frequency not supported 
25InBlock.gif                throw new Win32Exception(); 
26ExpandedSubBlockEnd.gif            }

27InBlock.gif 
28InBlock.gif            check = 0;
29InBlock.gif
30InBlock.gif            QueryPerformanceCounter(out start);
31InBlock.gif            QueryPerformanceCounter(out stop);
32InBlock.gif
33InBlock.gif            QueryPerformanceCounter(out start);
34InBlock.gif            QueryPerformanceCounter(out stop);
35InBlock.gif            check+=stop-start;
36ExpandedSubBlockEnd.gif        }
 
37InBlock.gif
38InBlock.gif        public void Start() 
39ExpandedSubBlockStart.gif        
40InBlock.gif            QueryPerformanceCounter(out start); 
41ExpandedSubBlockEnd.gif        }
 
42InBlock.gif
43InBlock.gif        public void Stop() 
44ExpandedSubBlockStart.gif        
45InBlock.gif            QueryPerformanceCounter(out stop); 
46ExpandedSubBlockEnd.gif        }
 
47InBlock.gif
48InBlock.gif        public double Duration(int iterations) 
49ExpandedSubBlockStart.gif        
50InBlock.gif            return ((((double)(stop - start-check)* (double) multiplier) / (double) frequency)/iterations); 
51ExpandedSubBlockEnd.gif        }
 
52ExpandedBlockEnd.gif    }

53None.gif

  采用下面这个方法测试校准效果:

 1None.gif        static void TestCheckPrecision()
 2ExpandedBlockStart.gif        {
 3InBlock.gif            QueryPerfCounter q;
 4InBlock.gif
 5InBlock.gif            int loop = 10000;
 6InBlock.gif            int exCount = 0;
 7InBlock.gif
 8InBlock.gif            for (int i=0;i<loop;i++)
 9ExpandedSubBlockStart.gif            {
10InBlock.gif                q = new QueryPerfCounter();
11InBlock.gif                q.Start();
12InBlock.gif                q.Stop();
13InBlock.gif                if(q.Duration(1)!=0)
14ExpandedSubBlockStart.gif                {
15InBlock.gif                    exCount++;
16InBlock.gif                    Console.WriteLine("QueryPerfCounter时间精度异常:{0}ns",q.Duration(1));
17ExpandedSubBlockEnd.gif                }

18ExpandedSubBlockEnd.gif            }

19InBlock.gif
20InBlock.gif            Console.WriteLine("共进行{0}次QueryPerfCounter的时间精度测试",loop);
21InBlock.gif            Console.WriteLine("其中{0}次QueryPerfCounter的时间精度异常",exCount);
22InBlock.gif            Console.WriteLine("时间校准有效性{0}%",100-(100.0*exCount)/loop);
23ExpandedBlockEnd.gif        }

24None.gif

运行结果:

QueryPerfCounter时间精度异常:-838.095344520044ns
QueryPerfCounter时间精度异常:-558.730229680029ns
QueryPerfCounter时间精度异常:-558.730229680029ns
QueryPerfCounter时间精度异常:-838.095344520044ns
QueryPerfCounter时间精度异常:-838.095344520044ns
QueryPerfCounter时间精度异常:-838.095344520044ns
QueryPerfCounter时间精度异常:-838.095344520044ns
QueryPerfCounter时间精度异常:-558.730229680029ns
QueryPerfCounter时间精度异常:-838.095344520044ns
QueryPerfCounter时间精度异常:-838.095344520044ns
QueryPerfCounter时间精度异常:-558.730229680029ns
QueryPerfCounter时间精度异常:-558.730229680029ns
QueryPerfCounter时间精度异常:-838.095344520044ns
QueryPerfCounter时间精度异常:-345854.012171938ns
QueryPerfCounter时间精度异常:279.365114840015ns
QueryPerfCounter时间精度异常:-55314.2927383229ns
QueryPerfCounter时间精度异常:279.365114840015ns
QueryPerfCounter时间精度异常:5307.93718196028ns
QueryPerfCounter时间精度异常:279.365114840015ns
QueryPerfCounter时间精度异常:279.365114840015ns
QueryPerfCounter时间精度异常:279.365114840015ns
共进行10000次QueryPerfCounter的时间精度测试
其中22次QueryPerfCounter的时间精度异常
时间校准有效性99.78%

也就是说99.78%情况下都得到了很好的校准,只有极少数情况校准会出现异常现象不为零,有时这一波动甚至很大,到了5.3微妙。这个结果很满意了,因为异常的测试结果可以很简单的发现出来。但是是不是说明,校准后的类的测量误差就差不多就是纳秒级的呢?我后来又做了一个测试发现不是这样,测试代码如下:

 1None.gif        static void TestPrecision()
 2ExpandedBlockStart.gif        {
 3InBlock.gif            QueryPerfCounter q;
 4InBlock.gif
 5InBlock.gif            for(int j=0;j<200;j++)
 6ExpandedSubBlockStart.gif            {
 7InBlock.gif                q = new QueryPerfCounter();
 8InBlock.gif
 9InBlock.gif                q.Start();
10InBlock.gif                q.Stop();
11InBlock.gif
12InBlock.gif                Console.WriteLine(""); 
13InBlock.gif
14InBlock.gif                Console.WriteLine("QueryPerfCounter时间精度:{0}ns",q.Duration(1)); 
15InBlock.gif
16InBlock.gif                q.Start();
17InBlock.gif                int i=0;
18InBlock.gif                for(i=0;i<j;i++)
19ExpandedSubBlockStart.gif                {
20InBlock.gif                    int l;
21ExpandedSubBlockEnd.gif                }

22InBlock.gif                q.Stop();
23InBlock.gif
24InBlock.gif                Console.WriteLine("第{0}次循环,耗时{1}ns",i,q.Duration(1));
25ExpandedSubBlockEnd.gif            }

26ExpandedBlockEnd.gif        }

27None.gif

 对于循环
    for(i=0;i<j;i++)
    {
     int l;
    }

当j很小的时候,耗时为0ns,随着n逐渐增大,耗时会一下子跳到279.365114840015ns,然后是558.730229680029ns。我摘几条结果:

QueryPerfCounter时间精度:0ns
第73次循环,耗时0ns

QueryPerfCounter时间精度:0ns
第74次循环,耗时279.365114840015ns

QueryPerfCounter时间精度:0ns
第75次循环,耗时0ns

QueryPerfCounter时间精度:0ns
第76次循环,耗时279.365114840015ns

QueryPerfCounter时间精度:0ns
第88次循环,耗时558.730229680029ns

QueryPerfCounter时间精度:0ns
第89次循环,耗时279.365114840015ns

也就是说,对我的机器现在配置来说(1.5G迅驰,2003 server,.net framework 1.1),测量的最基本时间单位是279.365114840015ns,不能得出更精确的时间了。

因此,推荐的测试方法是采用校对后的QueryPerfCounter,多测量几次,去掉最高值,去掉最低值(这两个一定要去掉),然后取平均值,这样能够得到非常精确的测量结果,测量误差约为0.3微妙。

本文转自xiaotie博客园博客,原文链接http://www.cnblogs.com/xiaotie/archive/2005/08/16/216015.html如需转载请自行联系原作者


xiaotie 集异璧实验室(GEBLAB)

版权声明:本文内容由阿里云实名注册用户自发贡献,版权归原作者所有,阿里云开发者社区不拥有其著作权,亦不承担相应法律责任。具体规则请查看《阿里云开发者社区用户服务协议》和《阿里云开发者社区知识产权保护指引》。如果您发现本社区中有涉嫌抄袭的内容,填写侵权投诉表单进行举报,一经查实,本社区将立刻删除涉嫌侵权内容。

分享:
云计算
使用钉钉扫一扫加入圈子
+ 订阅

时时分享云计算技术内容,助您降低 IT 成本,提升运维效率,使您更专注于核心业务创新。

其他文章