Time difference in .NET

I have the following code in a WinForm:

  Protected Overrides Sub OnMouseMove(ByVal e As System.Windows.Forms.MouseEventArgs)
    Dim startTime = DateTime.Now
    MyBase.OnMouseMove(e)

    Dim result As Double = 45654654
    For i = -1000 To 1000
      result = result / i
    Next i

    Dim endTime = DateTime.Now
    Console.WriteLine(">>> OnMouseMove time = {0}(ms) (start={1}:{3}; end={2}:{4})", (endTime - startTime).TotalMilliseconds, startTime.ToLongTimeString(), endTime.ToLongTimeString(), startTime.Ticks, endTime.Ticks)
  End Sub

This is incredible, but it seems that is take any millisecond that operations... ANY TICK!!!

the result is

>>> OnMouseMove time = 0(ms) (start=15:56:03:634432317630699089; end=15:56:03:634432317630699089)
>>> OnMouseMove time = 0(ms) (start=15:56:03:634432317630855340; end=15:56:03:634432317630855340)
>>> OnMouseMove time = 0(ms) (start=15:56:03:634432317630855340; end=15:56:03:634432317630855340)
>>> OnMouseMove time = 0(ms) (start=15:56:03:634432317631011591; end=15:56:03:634432317631011591)
>>> OnMouseMove time = 0(ms) (start=15:56:03:634432317631011591; end=15:56:03:634432317631011591)
>>> OnMouseMove time = 0(ms) (start=15:56:03:634432317631167842; end=15:56:03:634432317631167842)

Do I something wrong?

In an other varaint I try to sleep 100 ms

Next i

' sleep 100 ms '
System.Threading.Thread.Sleep(100)

Dim endTime = DateTime.Now

, but here surprise, innstead of 100 I gel always 93,7506 or 109,3757:

>>> OnMouseMove time = 93,7506(ms) (start=16:05:26:634432323267766416; end=16:05:26:634432323268703922)
>>> OnMouseMove time = 93,7506(ms) (start=16:05:26:634432323268860173; end=16:05:26:634432323269797679)
>>> OnMouseMove time = 109,3开发者_JS百科757(ms) (start=16:05:26:634432323269797679; end=16:05:27:634432323270891436)
>>> OnMouseMove time = 93,7506(ms) (start=16:05:27:634432323270891436; end=16:05:27:634432323271828942)
>>> OnMouseMove time = 93,7506(ms) (start=16:05:27:634432323271828942; end=16:05:27:634432323272766448)
>>> OnMouseMove time = 109,3757(ms) (start=16:05:31:634432323315891724; end=16:05:31:634432323316985481)

As you don't use i outside the loop it is probably optimised away. Thus you are timing two calls to DateTime.Now and a subtraction.

Additionally, with recent CPUs able to dispatch billions of operations per second, a mere few thousand operations (from L1 cache and registers as little data is involved) will take time measured in *micro*seconds.

BTW. If you want to do timings the Stopwatch type is a better approach.

DateTime.Now doesn't have a high accuracy. Typically it's around 16ms by default and get be reduced to 1ms using timeBeginPeriod. Note that timeBeginPeriod has system wide effects and can increase the power consumption of the computer. So it should not be used lightly.

Imagine you have a timer in the kernel which runs a certain function every 16ms. This function updates the current time used by DateTime.Now. Then it decides which thread to run for the next 16ms.
If you call sleep(100) your thread won't run for the next about 100ms. But windows doesn't instantly notice that the 100ms are up. It only notices on the next timer event. And then it decides to run your thread again.

This is related to the timer granularity in windows and affects many windows api functions such as GetTickCount, Sleep, thread scheduling and timer intervals.

To measure performance use the StopWatch class which is based on QueryPerformanceCounter and doesn't suffer from this problem. (Unfortunately it is buggy on some multicore machines where the clocks of different cores desync. Don't be surprised if it jumps backward or forward in time for larger intervals when your thread gets scheduled on another core)

When trying to measure the elapsed time of processes, particularly short-running processes, you want to utilize a better tool, System.Diagnostics.Stopwatch.

DateTime.Now is not going to have the appropriate combination of precision and accuracy for measuring process duration.

For more information, I encourage you to check Eric Lippert's blog entry.

you must use the stop watch

as others has posted

further..

your loop :

Dim result As Double = 45654654
For i = -1000 To 1000
  result = result / i
Next i

will be remove

by JIT COMPILER if you have

the optimisation so is not of use

Try using a stopwatch, but it I could see it taking less than a millisecond to increment an integer 2000 times, given that a modern computers think in terms of nanoseconds.

Yes. Using DateTime.Now to measure precise timing is not precise. Use Stopwatch instead.