dotnet下时间精度测量

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

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

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

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

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

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

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

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

结果：

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微妙，这主要是因为方法调用和执行要花去一些时间。为了得到更精确的时间测量，必须对此进行时间校准，扣除方法调用和执行的时间.我在构造函数里面加了校准项。完整代码如下：

 1using System;
 2using System.ComponentModel; 
 3using System.Runtime.InteropServices;
 4
 5    public class QueryPerfCounter 
 6    { 
 7        [DllImport("KERNEL32")] 
 8        private static extern bool QueryPerformanceCounter( 
 9            out long lpPerformanceCount); 
10
11        [DllImport("Kernel32.dll")] 
12        private static extern bool QueryPerformanceFrequency(out long lpFrequency); 
13        
14        private long check;
15        private long start; 
16        private long stop; 
17        private long frequency; 
18        Decimal multiplier = new Decimal(1.0e9); 
19
20        public QueryPerfCounter() 
21        { 
22            if (QueryPerformanceFrequency(out frequency) == false) 
23            { 
24                // Frequency not supported 
25                throw new Win32Exception(); 
26            }
27 
28            check = 0;
29
30            QueryPerformanceCounter(out start);
31            QueryPerformanceCounter(out stop);
32
33            QueryPerformanceCounter(out start);
34            QueryPerformanceCounter(out stop);
35            check+=stop-start;
36        } 
37
38        public void Start() 
39        { 
40            QueryPerformanceCounter(out start); 
41        } 
42
43        public void Stop() 
44        { 
45            QueryPerformanceCounter(out stop); 
46        } 
47
48        public double Duration(int iterations) 
49        { 
50            return ((((double)(stop - start-check)* (double) multiplier) / (double) frequency)/iterations); 
51        } 
52    }
53

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

 1        static void TestCheckPrecision()
 2        {
 3            QueryPerfCounter q;
 4
 5            int loop = 10000;
 6            int exCount = 0;
 7
 8            for (int i=0;i<loop;i++)
 9            {
10                q = new QueryPerfCounter();
11                q.Start();
12                q.Stop();
13                if(q.Duration(1)!=0)
14                {
15                    exCount++;
16                    Console.WriteLine("QueryPerfCounter时间精度异常：{0}ns",q.Duration(1));
17                }
18            }
19
20            Console.WriteLine("共进行{0}次QueryPerfCounter的时间精度测试",loop);
21            Console.WriteLine("其中{0}次QueryPerfCounter的时间精度异常",exCount);
22            Console.WriteLine("时间校准有效性{0}%",100-(100.0*exCount)/loop);
23        }
24

运行结果：

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微妙。这个结果很满意了，因为异常的测试结果可以很简单的发现出来。但是是不是说明，校准后的类的测量误差就差不多就是纳秒级的呢？我后来又做了一个测试发现不是这样，测试代码如下：

 1        static void TestPrecision()
 2        {
 3            QueryPerfCounter q;
 4
 5            for(int j=0;j<200;j++)
 6            {
 7                q = new QueryPerfCounter();
 8
 9                q.Start();
10                q.Stop();
11
12                Console.WriteLine(""); 
13
14                Console.WriteLine("QueryPerfCounter时间精度：{0}ns",q.Duration(1)); 
15
16                q.Start();
17                int i=0;
18                for(i=0;i<j;i++)
19                {
20                    int l;
21                }
22                q.Stop();
23
24                Console.WriteLine("第{0}次循环，耗时{1}ns",i,q.Duration(1));
25            }
26        }
27

 对于循环
    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微妙。