logging module -- better timestamp accuracy on Windows

benhoyt benhoyt at gmail.com
Wed Feb 16 13:29:00 EST 2011


> For example, are you assuming that your clock() call in logging is
> the very first call made?

Yes, we were making that assumption (the time.clock() call in the import of our log module), which was true in our code, but I can see where it's not a good thing to assume generally.

> Also, IIUC the resolution of clock() is < 1 usec, but
> as logging only prints to the nearest msec, won't you lose much of the
> benefit of the increased resolution? ...
> Or are you saying that the times should be formatted/printed to
> microsecond accuracy?

No, millisecond is fine. The 0.56ms example I gave in response to Rick was a really bad example -- It's more like when it's 5.6 ms that it's a problem for us, because the request time is saying 5.6ms, but the log timestamps within and at the end of that request are identical.

Anyway, as sturlamolden mentioned, time.clock() has long-term accuracy issues (gets out of sync with time.time()), so that's not really a good solution.

So the way it is is non-ideal, but that's more a fact of life due to the Windows time functions than anything else. It's not trivial to solve, so we're going to leave it for now, and just use time.clock() to time individual pieces of code when we need more accuracy...

-Ben



More information about the Python-list mailing list