Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Timer shows negative time elapsed

Tags:

python

time

I'm using a quite simple code to time each loop in a for statement. It looks something like this:

import time

for item in list_of_files:

    # Start timing this loop.
    start = time.clock()

    # Do a bunch of stuff.

    # Get time elapsed in seconds.
    elapsed = time.clock() - start

    # Get minutes and seconds.
    m, s = divmod(elapsed, 60)

    # Print result.
    print 'End of analysis for %s in %dm %02ds.\n'% (item, m, s)

This will most of the times result in correct outputs like 9m 52s but sometimes with large loops (that take some time) I get negative results like -53m 17s.

I can't pinpoint a clear limit where results start showing as negative values but it apparently only happens for elapsed times > 20 min, but not for every loop that took > 20 min (ie: it's not consistent).

Is there something in my code to time each loop that's causing this?

Add

I'm using Spyder as my IDE. I compared how time.clock() behaved vs time.time() and this is what I see:

>>> st1, st2 = time.clock(), time.time()
>>> st1,st2
(507.65, 1374502193.357196)
>>> print time.clock()-st1, time.time()-st2
0.14 15.1921429634
>>> print time.clock()-st1, time.time()-st2
0.34 35.0087578297
>>> print time.clock()-st1, time.time()-st2
0.67 69.8715758324
>>> print time.clock()-st1, time.time()-st2
0.77 80.0557789803
>>> print time.clock()-st1, time.time()-st2
1.25 130.559605837
>>> print time.clock()-st1, time.time()-st2
3.02 309.845729828
>>> print time.clock()-st1, time.time()-st2
8.9 899.936934948

Shouldn't time.clock() return the time elapsed in seconds? The time.time() call keeps accurate track of the elapsed time in seconds (for example, the last call is made after 15 mins had passed which equals 900 sec) but I have no idea what time.clock() is doing.

like image 950
Gabriel Avatar asked Jul 22 '13 13:07

Gabriel


2 Answers

I suspect that you're getting some kind of overflow.

http://linux.die.net/man/3/clock

The linux man page for clock suggests that the return values for clock cycle, so if happen to clock start at a high value and stop at a low value, and your difference is signed, you might get a negative value for time elapsed.

Since you're timing events that go on for multiple seconds, maybe the time.time() function would be more appropriate for what you're doing.

like image 130
Zhe Avatar answered Oct 15 '22 12:10

Zhe


time.clock() measures CPU time on Unix systems, not wall time. See http://pubs.opengroup.org/onlinepubs/007908799/xsh/clock.html for more info on the underlying system call (note the part where it says it can wrap).

If you want to measure walltime, use time.time().

like image 21
Fredrik Avatar answered Oct 15 '22 12:10

Fredrik