Sunday, November 18, 2007

DateTime.Now Precision

While re-evaluating the numbers from yesterday's post NHibernate Access Performance, I thought that the returned time in milliseconds seemed a bit strange. Specifically the repeat of 13.67 and 15.62 milliseconds. What are the odds that you see the exact same values twice while running the tests I was running? I started to wonder about how precise the DateTime.Now (or DateTime.UtcNow) values really are. I always assumed they would be updated once the ticks of the processor are incremented. It doesn't look like that is the case.

For fun try running a console application where you write the current time in ticks to the screen two commands in a row. They are exactly the same. At least they were for me.

Now for more fun try the following code:


DateTime now = DateTime.UtcNow;
while (now == DateTime.UtcNow) { }
Console.WriteLine(((TimeSpan)(DateTime.UtcNow - now)).TotalMilliseconds);


When I first wrote this code and tried it, it returned 15.624 milliseconds every single time (A common value I see while running my performance tests from yesterday). However, now when I run it I see .9765 milliseconds every time. Something is controlling the precision of the DateTime.Now and I have no idea what.

I would have expected something like this to have been publicized more. I've never seen articles written explaining the precision of DateTime.Now. The lack of precision seems like it could be an issue for systems which perform many transactions per second. It seems like it would be helpful to be able to guarantee order based on time. That unfortunately doesn't seem to be the case anymore.

As a result of these findings I think I'm going to re-run the tests from yesterday regarding private field access versus public property access in NHibernate. When ran for longer periods of times the results are actually a little bit different than what we saw before. Not different enough to change my conclusions, but different enough to be interesting none the less.

I've also been trying to hunt down how the reflection optimizer is actually helping with the private field access. From the code I see in NHibernate it looks like the performance should be identical to my non optimized getter/setter for the fields. Look for more information to come on that topic if I find it.

2 comments:

Bitstar said...

what you are seeing is not the precision but the time needed to execute the sequence. The reason it's not constant is because of the unpredictable nature of OS interrupts and context switches.

Jeff said...

that doesn't make sense. his problem is that it *is* constant, whereas time changes. i've seen this as well and have never found a satisfactory answer for it. seems to be a bug (or at least poorly documented limitation) in .net.

Blogger Syntax Highliter