Anomaly in time.clock()

[Godzilla]

Hello,

I have been reading a thread about time.clock() going backward, which
is exactly what I am seeing... the thread generally leaning toward the
problem is caused by multi-processor machines. But I am seeing it at a
single CPU computer, and running XP.

The error I am seeing between two very close invokation of
time.clock() is always around 3.5 seconds! This is enough to throw a
lot of the timing requirement in the software out of the window...
this is a fairly serious problem. A quick fix will be to capture the
time.clock() going backward 3.5 seconds, and then adjust rest of the
system accordingly. But I don't feel like this is a good way around
this problem. I was using time.time() before switching to
time.clock(). The reason I changed is because I need a way to
calculate elapsed time independent of system time.

Should I just stick with time.time() instead? Or is there another way
to calculate elapsed time accurately, independent of system time being
changed?

 

[Roel Schroeven]

Godzilla schreef:

Hello,

I have been reading a thread about time.clock() going backward, which
is exactly what I am seeing... the thread generally leaning toward the
problem is caused by multi-processor machines. But I am seeing it at a
single CPU computer, and running XP.

The error I am seeing between two very close invokation of
time.clock() is always around 3.5 seconds! This is enough to throw a
lot of the timing requirement in the software out of the window...
this is a fairly serious problem.

I don't know if it's the same problem, but I've seen something similar
to this. Are you by any chance using DirectX? When you create a DirectX
device, DirectX by default resets the precision of the CPU to 20 bits or so.

I had that problem in a project at work, with similar results (and other
strange calculation errors). The solution was to use a flag
(PRESERVE_PRECISION or something like that) in the CreateDevice() call
(it was a C++ project).

If it's something else, I'm afraid I can't help.

--
The saddest aspect of life right now is that science gathers knowledge
faster than society gathers wisdom.
-- Isaac Asimov

Roel Schroeven

 

[Godzilla]

Thanks Roel. If there is a way to pass in the PRESERVE_PRECISION
constant in the python time.clock library, that would be great. But
I'm afraid it's not possible. I think I will change away from using
time.clock() from now on... seems too edgy to me.

Thank you for sharing your experience with me nonetheless.

Cheers mate.

 

[John Machin]

Thanks Roel. If there is a way to pass in the PRESERVE_PRECISION
constant in the python time.clock library, that would be great

Re-read Roel's message. Something like PRESERVE_PRECISION is to be
passed to whatever is setting up DirectX.

But
I'm afraid it's not possible. I think I will change away from using
time.clock() from now on... seems too edgy to me.

Are you using DirectX? If so, read the docs for more clues -- a quick
google for "PRESERVE_PRECISION" will tell you that "something like"
means what it says. If not, try posting some more info on what you are
actually doing. Consider providing a short piece of code that
demonstrates the actual problem.

 

[Godzilla]

Hi John,

I am using time.clock to calculate the elapsed time. Below is an
example of what I was trying to do:


import time
import thread

class elapseTime:
def __init__(self, name=''):
self.name = name
self.timeStamp = None
self.checkTimeFlag = False
thread.start_new_thread(self.elapsedTime, ())

def setTime(self, state):
if state == 1:
self.checkTimeFlag = True
self.timeStamp = time.clock()
else:
self.checkTimeFlag = False

def elapsedTime(self):
while True:
curTime = time.clock()
if self.checkTimeFlag:
if (curTime - self.timeStamp) > 1.0:
print "Elapsed time greater than 1 second. Actual Elapsed
Time", round(curTime-self.timeStamp, 3)
self.checkTimeFlag = False
prevTime = curTime
time.sleep(0.05)

obj = elapseTime()

while True:
obj.setTime(1)
time.sleep(10)


But the time.clock() sometimes return a value of between -3.5 to -4.5
seconds backward. Note that not all computers are behaving the same. I
have not experience the same problem with the computer at home.

 

[Ross Ridge]

But the time.clock() sometimes return a value of between -3.5 to -4.5
seconds backward.

There are race conditions in your code. In between the time you execute
"curTime = time.clock()" and calculate "curTime - self.timeStamp" in one
thread, the other thread can execute "self.timeStamp = time.clock()".
It's the only way your example program can print a negative "Actual
Elapsed Time" value. The race condition seems unlikely, and it's hard
to explain how this could result in it printing a value in the range
of -3.5 to -4.5. However, a race condition occuring between the two
evaluations of "curTime - self.timeStamp" is the only way your example
program could print a negative value.

Ross Ridge

 

[John Machin]

Hi John,

I am using time.clock to calculate the elapsed time. Below is an
example of what I was trying to do:

import time
import thread

Silly me, not being able to infer that from your initial post!

[snip]

But the time.clock() sometimes return a value of between -3.5 to -4.5
seconds backward. Note that not all computers are behaving the same. I
have not experience the same problem with the computer at home.

Same "service pack" number?

Your code "worked" (no time warp) for me on a single-core AMD Turion64
CPU running (32 bit) Windows XP Service Pack 2 Build 2600. Maybe the
ones that "fail" have dual-core CPUs.

 

[Godzilla]

Thanks Ross and John for your help. I apologise for the code I posted
earlier not being the full picture of what I was trying to achieve. I
had instantiated multiple instances of elapseTime class and each of
them gets called approximately the same time. Below is the updated
code:


import time
import thread
import Queue

printq = Queue.Queue(0)

class elapseTime:
def __init__(self, name=''):
self.name = name
self.timeStamp = None
self.checkTimeFlag = False
thread.start_new_thread(self.elapsedTime, ())

def setTime(self, state):
if state == 1:
self.checkTimeFlag = True
self.timeStamp = time.clock()
else:
self.checkTimeFlag = False

def elapsedTime(self):
prevTime = time.clock()
while True:
curTime = time.clock()
timeDiff = (curTime - prevTime)
if timeDiff < 0.0:
printq.put_nowait('time.clock() has gone backward!!! Time
Diff '+str(timeDiff))
if self.checkTimeFlag:
if (curTime - self.timeStamp) > 1.0:
printq.put_nowait(self.name+", actual Elapsed
Time"+str(round(curTime-self.timeStamp, 3)))
self.checkTimeFlag = False
prevTime = curTime
time.sleep(0.05)

def printmgr():
while True:
print printq.get(True)

# Print thread
thread.start_new_thread(printmgr, ())

objList = []
for i in range(10):
objList.append(elapseTime("obj"+str(i)))

while True:
for i in range(len(objList)):
objList.setTime(1)
time.sleep(10)
print


When I run the above code long enough in the PC I see the
'time.clock() has gone backward!!!' statement being printed once in a
while. I have been reading a thread about invoking time.clock() at
close proximity caused the 'time warp' problem.

John, the PC experiencing this problem is a single core Intel Celeron
1GHz, XP SP2. The PC at home is a AMD Dual Core XP SP2.

 

[Godzilla]

Just found out that win32api.GetTickCount() returns a tick count in
milli-second since XP started. Not sure whether that is reliable.
Anyone uses that for calculating elapsed time?

 

[Gabriel Genellina]

Thanks Ross and John for your help. I apologise for the code I posted
earlier not being the full picture of what I was trying to achieve. I
had instantiated multiple instances of elapseTime class and each of
them gets called approximately the same time. Below is the updated
code:

You still have race conditions:

    def setTime(self, state):
      if state == 1:
        self.checkTimeFlag = True
        self.timeStamp = time.clock()
      else:
        self.checkTimeFlag = False

    def elapsedTime(self):
      prevTime = time.clock()
      while True:
        curTime = time.clock()
        timeDiff = (curTime - prevTime)
        if timeDiff < 0.0:
          printq.put_nowait('time.clock() has gone backward!!! Time
Diff '+str(timeDiff))
        if self.checkTimeFlag:
          if (curTime - self.timeStamp) > 1.0:
            printq.put_nowait(self.name+", actual Elapsed
Time"+str(round(curTime-self.timeStamp, 3)))
            self.checkTimeFlag = False
        prevTime = curTime
        time.sleep(0.05)

Both functions run on different threads, use self.checkTimeFlag and
self.timeStamp.
By example, setTime sets self.checkTimeFlag = True before
self.timeStamp; the other thread can use and old value for
self.timeStamp.

 

[Gabriel Genellina]

Just found out that win32api.GetTickCount() returns a tick count in
milli-second since XP started. Not sure whether that is reliable.
Anyone uses that for calculating elapsed time?

I use GetTickCount on other languages because it's easy to call. Note
that it returns a value in ms but the *precision* may be not so high.
Anyway I think your problem is in the code, not on time.clock()

 

[Tim Roberts]

Just found out that win32api.GetTickCount() returns a tick count in
milli-second since XP started. Not sure whether that is reliable.
Anyone uses that for calculating elapsed time?

What do you mean by "reliable"? The tick count is updated as part of
scheduling during timer interrupts. As long as no one disables interrupts
for more than about 15ms, it is reliable.

However, it's only a 32-bit value, so the number rolls over every 49 days.

 

[Craig]

What do you mean by "reliable"? The tick count is updated as part of
scheduling during timer interrupts. As long as no one disables interrupts
for more than about 15ms, it is reliable.

However, it's only a 32-bit value, so the number rolls over every 49 days.

Try getting XP or Vista to stay up for 49 days. I have had Vista stay
up for a little over 11 days. If it doesn't crash, it will have to be
rebooted for some update or other.