How to get precise DateTime in C#

Question

I know that DateTime.UtcNow does not have a relatively high degree of precision (10-15 ms resolution).

This is a problem for me because in my log files, I want better resolution for the purposes of resolving race conditions.

The question is: how can I get the current date/time with a better precision than what DateTime.UtcNow offers?

The only solution which I've seen up till now has been this: https://stackoverflow.com/a/15008836/270348. Is that a suitable way to solve the problem?

@Cole"Cole9"Johnson the OP mentioned that "I want a better resolution for the purposes of resolving race conditions" — Dan Drews, Aug 15 '13 at 17:18
I think you need to work with the Win32 API then to get into the ns precision. — Cole Tobin, Aug 15 '13 at 17:19
You can't get better than 1 msec with timeBeginPeriod(), not nearly good enough for race conditions. Beware that just adding the logging already has a big effect on the race. You can make Stopwatch work. — Hans Passant, Aug 15 '13 at 17:20
Take a look at this question http://stackoverflow.com/questions/457605/how-to-measure-code-performance-in-net — Dan Drews, Aug 15 '13 at 17:21
You need to read this: `Precision and accuracy of DateTime`, Eric Lippert http://blogs.msdn.com/b/ericlippert/archive/2010/04/08/precision-and-accuracy-of-datetime.aspx — asawyer, Aug 15 '13 at 17:23
@HansPassant So are you saying that the solution I linked to in the question is viable? — RobSiklos, Aug 15 '13 at 17:26
@asawyer: No, I'm not interested in timing operations. I'm interested in knowing the relative time between two completely independent operations. I want a more precise "event time" for the entries in my log file. — RobSiklos, Aug 15 '13 at 17:27
@RobSiklos You don't want to use that linked solution. Every time it gets reset your time can jump 10ms in either direction. That would completely destroy your ability to determine the relative time between logging calls. You just want a single `Stopwatch` that is never reset. — Servy, Aug 15 '13 at 17:29
@Servy: so if I modify the linked solution so that it never resets, it's viable? — RobSiklos, Aug 15 '13 at 17:31
@RobSiklos At that point it's basically my exact answer, yes. If it never resets (and doesn't have a timer resetting it) then it's just one stopwatch adding it's interval to a `DateTime` taken at the start, which is *exactly* the solution that I proposed as an answer. — Servy, Aug 15 '13 at 17:32

score 10 · Accepted Answer · answered Aug 15 '13 at 17:21

10

You can use Stopwatch for more precise measurements of time. You can then have each log entry record the time from the start of the first operation. If it's important, you can record the DateTime of the first operation and therefore calculate the times of the rest, but it sounds like just having the ticks/nanoseconds since the start of the first operation is good enough for your purposes.

answered Aug 15 '13 at 17:21

Servy

202,030
26
332
449

2

Worth noting that Stopwatch drifts relative to wall clock time, so taking a DateTime.UtcNow on start-up and then adding a Stopwatch-derived offset will only work to produce timestamps that are "correct" relative to each other in the same system, not across systems. The accuracy will be quite poor over time (the Internet seems to think up to 0.2ms drift per second isn't uncommmon). – Alastair Maw Aug 09 '16 at 09:41

score 5 · Answer 2 · answered Aug 15 '13 at 17:42

If you want to add tracing you could write your own ETW Trace Provider like here. Then you do not need to take care how the timing is fetched. The Windows Kernel will take care that the timing is accurate and the order of the events is correct.

If you do not want to write your own ETW Provider you can use EventSource which is available as Nuget Package which allows you to use it from .NET 4.0 as well. More infos has Vance Morrison on his blog.

When use ETW events then you get a powerful trace analyzer for free with the Windows Performance Toolkit. As added bonus you can do system wide profiling in all processes with minimal impact as well.

This allows you to selectively add call stacks for every event you write which can be invaluable when you want to track down who did call your Dispose method two times.

enter image description here

xanatos · Answer 3 · 2013-08-15T17:32:17.620

2

Do you really need a precise timer or what you really need is something that give a sort? For example:

static class AutoIncrement
{
    private static long num;

    public static long Current
    {
        get
        {
            return Interlocked.Increment(ref num);
        }
    }
}

Console.WriteLine(AutoIncrement.Current);
Console.WriteLine(AutoIncrement.Current);
Console.WriteLine(AutoIncrement.Current);
Console.WriteLine(AutoIncrement.Current);
Console.WriteLine(AutoIncrement.Current);

This is guaranteed to be unique, and to change every time, and to be sorted. Its precision is better than microsecond. Its precision is absolute on a single PC.

or if you really want Timestamps...

static class AutoIncrement
{
    private static long lastDate;

    public static DateTime Current
    {
        get
        {
            long lastDateOrig, lastDateNew;

            do
            {
                lastDateOrig = lastDate;

                lastDateNew = lastDateOrig + 1;

                lastDateNew = Math.Max(DateTime.UtcNow.Ticks, lastDateNew);
            }
            while (Interlocked.CompareExchange(ref lastDate, lastDateNew, lastDateOrig) != lastDateOrig);

            return new DateTime(lastDateNew, DateTimeKind.Utc);
        }
    }
}

DateTime ac = AutoIncrement.Current;
Console.WriteLine(CultureInfo.InvariantCulture, "{0} {1:yyyy/MM/dd HH:mm:ss.fffffff}", ac.Ticks, ac);

This last variant uses as a base DateTime.UtcNow, but each call if it isn't changed, it increments it by one.

edited Aug 15 '13 at 17:32

answered Aug 15 '13 at 17:25

xanatos

109,618
12
197
280

No - I want more precise event timestamps in my log file. – RobSiklos Aug 15 '13 at 17:28
@RobSiklos Something like this? Each call is guaranteed to give at least a +1 Tick on the previous one. The precision is still 10ms, but you can differentiate between the calls. – xanatos Aug 15 '13 at 17:35
1

I'm not sure this works even on a single PC. The line you want to log runs in thread1, thread2 is switched to, a logged line is ran there, thread2 retrieves a number, thread1 is switched back to, it retrieves a number -> race condition (if you log before you run the line, a similar problem happens). The only thing Interlocked will guarantee is that no two entries will have the same number, but not that they won't get the numbers in the incorrect order. So you'd need to use locking to ensure a thread runs the line and retrieves a number without another thread being able to do it in between. – svinja Aug 15 '13 at 17:36
@svinja The only solution in that case is that the logger takes a lock on the timer and release it after having finished writing. Each other solution will have the same problem. And even then, what you'll have is the order of logging, not the order of operations. – xanatos Aug 15 '13 at 17:39
You need to lock before you even run the line of code you want to log. lock -> run the line of code -> retrieve a number -> unlock. With this, I think you would always have the correct order. It doesn't matter whether you do the actual writing inside or outside the lock, you just have to retrieve the number inside the lock. – svinja Aug 15 '13 at 17:43
@svinja Yes... But then the problem isn't in the logger or in the timer... It's much further... And in truth you would have to: lock, do your operation, retrieve timer, write log, flush log, unlock – xanatos Aug 15 '13 at 17:44
This rather assumes your Stopwatch doesn't drift relative to the wallclock, which is a poor assumption. You need an algorithm that's more NTP-like, which does gradual corrections to slew things in line, or something like that. – Alastair Maw Aug 09 '16 at 09:45

How to get precise DateTime in C#

3 Answers3

Linked