Issue20101
This issue tracker has been migrated to GitHub,
and is currently read-only.
For more information,
see the GitHub FAQs in the Python's Developer Guide.
Created on 2013-12-31 21:42 by zach.ware, last changed 2022-04-11 14:57 by admin. This issue is now closed.
Messages (10) | |||
---|---|---|---|
msg207125 - (view) | Author: Zachary Ware (zach.ware) * | Date: 2013-12-31 21:42 | |
For previous discussion, see issue19999. To summarize, time on Windows is far from straight-forward, and currently for """ t1 = time.monotonic() time.sleep(0.5) t2 = time.monotonic() dt = t2-t1 """ dt may end up as very slightly smaller than 0.5 (0.4990000003017485 or so), 0.5, or somewhat larger than 0.5 (0.5150000001303852 or so); or 0.5 almost all of the time, depending on the machine in question. So far, two very different Win7 machines of mine both produced the first result, and Tim Peters' Vista machine produced the second. Both of mine report the resolution as 0.015600099999999999, Tim's reports 0.015625. See also http://stackoverflow.com/questions/7685762/windows-7-timing-functions-how-to-use-getsystemtimeadjustment-correctly and http://www.windowstimestamp.com/description for more related reading. Due to the issue, test_monotonic regularly fails for me. A simple workaround is to relax the lower bound of 0.5 <= dt <= 1.0 to 0.45; I intend to commit that workaround soon, but it won't close this issue. In preparation for creating this issue I also checked the other time functions (time, clock, and perf_counter) for the same issue, and on my test machine all of them have it (although it is apparently intermittent for time (earlier I got straight failures, now it won't fail), and clock and perf_counter are implemented by the same underlying function). Here is some output from my machine, formatted slightly for nicer presentation: 3.4.0b1 (default:fd846837492d+, Dec 30 2013, 11:01:01) [MSC v.1600 32 bit (Intel)] Windows-7-6.1.7601-SP1 Running: """ import time import sys import platform print(sys.version) print(platform.platform()) with open(__file__) as file: print('Running:\n"""') print(file.read()) print('"""') clock_info = {} for time_func in (time.monotonic, time.time, time.clock, time.perf_counter): name = time_func.__name__ info = str(time.get_clock_info(name)) print(name, info) if info in clock_info: print('Same clock as time.{}'.format(clock_info[info])) continue else: clock_info[info] = name good = 0 values = {} count = 0 try: while count < 25: # basic test copied from test_monotonic, extras bolted on t1 = time_func() time.sleep(0.5) t2 = time_func() dt = t2 - t1 if values.get(dt): values[dt] += 1 else: values[dt] = 1 assert t2 > t1 passed = 0.5 <= dt <= 1.0 print('.' if passed else 'F', end='', flush=True) if passed: good += 1 count += 1 except KeyboardInterrupt: pass print() print('total:', count, 'good:', good, 'bad:', count - good) print(sorted(values.items())) print() """ monotonic namespace(adjustable=False, implementation='GetTickCount64()', monotonic=True, resolution=0.015600099999999999) FF.FFFF.FFF.FF.FFF.FFFF.F total: 25 good: 6 bad: 19 [(0.4989999998360872, 13), (0.4990000003017485, 6), (0.5, 5), (0.5150000001303852, 1)] time namespace(adjustable=True, implementation='GetSystemTimeAsFileTime()', monotonic=False, resolution=0.015600099999999999) ......................... total: 25 good: 25 bad: 0 [(0.5, 25)] clock namespace(adjustable=False, implementation='QueryPerformanceCounter()', monotonic=True, resolution=2.851518034140655e-07) .FFFFFFFFFFFFFFFFFF.FFFFF total: 25 good: 2 bad: 23 [(0.49929681565278194, 1), (0.49941258728496685, 1), (0.4995377689266647, 1), (0.4995543077312634, 1), (0.49955459288306736, 1), (0.4995597256155282, 1), (0.4995602959191352, 1), (0.4995659989552035, 1), (0.4995679950178271, 1), (0.49956970592864813, 1), (0.4995748386611094, 1), (0.499581967456195, 1), (0.4995956547427589, 1), (0.49961304900276726, 1), (0.49961761143162153, 1), (0.49961846688703204, 1), (0.49962445507490294, 1), (0.499629017503759, 1), (0.4996355759952369, 1), (0.4996401384240914, 1), (0.49964042357589467, 1), (0.4996486929781927, 1), (0.4996555366214759, 1), (0.5000139724383673, 1), (0.5036356854935278, 1)] perf_counter namespace(adjustable=False, implementation='QueryPerformanceCounter()', monotonic=True, resolution=2.851518034140655e-07) Same clock as time.clock And here's results from time.time earlier today (produced by an earlier version of the above script, same machine and interpreter): time FFFFFFFFFFFFFFFFFFFFFF.FF total: 25 good: 1 bad: 24 [(0.49969983100891113, 7), (0.49970006942749023, 17), (0.5006990432739258, 1)] |
|||
msg207141 - (view) | Author: Tim Peters (tim.peters) * | Date: 2014-01-02 02:03 | |
I'm not sanguine about fixing any of this :-( The Microsoft docs are awful, and the more web searches I do the more I realize that absolutely everyone is confused, just taking their best guesses. FYI, here are results from your new program on my 32-bit Vista box: 3.4.0b1 (default:9d1fb265b88a, Dec 10 2013, 18:48:53) [MSC v.1600 32 bit (Intel)] Windows-Vista-6.0.6002-SP2 Running: ... monotonic namespace(adjustable=False, implementation='GetTickCount64()', monotonic=True, resolution=0.015625) ......................... total: 25 good: 25 bad: 0 [(0.5, 25)] time namespace(adjustable=True, implementation='GetSystemTimeAsFileTime()', monotonic=False, resolution=0.015625) FFFFFFFFFFFFFFFFFFFFFFFFF total: 25 good: 0 bad: 25 [(0.4999678134918213, 5), (0.4999680519104004, 20)] clock namespace(adjustable=False, implementation='QueryPerformanceCounter()', monotonic=True, resolution=2.793651148400146e-07) FFFFFFFFFFFFFFFFFFFF.FFFF total: 25 good: 1 bad: 24 [(0.49919109830998076, 1), (0.4996682539261279, 1), (0.4997051301212867, 1), (0.4997221713932909, 1), (0.49972636187001385, 1), (0.499727479330474, 1), (0.49973139044208104, 1), (0.49973390472811463, 1), (0.4997383745699526, 1), (0.49974479996759325, 1), (0.4997501079047755, 1), (0.4997501079047756, 1), (0.49975318092104004, 1), (0.499756533302417, 1), (0.4997598856837939, 1), (0.49976239996982863, 1), (0.49976714917678144, 1), (0.49977078092327387, 1), (0.49977189838373315, 1), (0.4997724571139628, 1), (0.499777765051145, 1), (0.49979173330688553, 1), (0.4997973206091828, 1), (0.4998065396579734, 1), (0.500726488981142, 1)] perf_counter namespace(adjustable=False, implementation='QueryPerformanceCounter()', monotonic=True, resolution=2.793651148400146e-07) Same clock as time.clock |
|||
msg207162 - (view) | Author: Martin v. Löwis (loewis) * | Date: 2014-01-02 13:20 | |
As a further datapoint, it would be good to find out whether any of you has NTP enabled, and if so, against what time server. To find out, open the clock settings ("Datums- und Uhrzeiteinstellungen ändern"), and go to NTP tab ("Internetzeit"). |
|||
msg207165 - (view) | Author: STINNER Victor (vstinner) * | Date: 2014-01-02 14:01 | |
time.get_clock_info("time") and time.get_clock_info("monotonic") is currently using GetSystemTimeAdjustment(). In msg206886 it was said that "GetSystemTimeAdjustment is not the function to look at." Should we modify this function to use NtQueryTimerResolution() instead? TimeAdjustmentDisabled argument of GetSystemTimeAdjustment() is current ignored. Is it a bug? |
|||
msg207167 - (view) | Author: Zachary Ware (zach.ware) * | Date: 2014-01-02 14:54 | |
Martin v. Löwis wrote: > As a further datapoint, it would be good to find out whether any of you has NTP enabled, and if so, against what time server. To find out, open the clock settings ("Datums- und Uhrzeiteinstellungen ändern"), and go to NTP tab ("Internetzeit"). My 32-bit box is on a domain, and thus I can't access that tab. However, according to HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows\CurrentVersion\DateTime\Servers (see [1]) it looks to me like NTP is enabled, with 5 servers listed: time.windows.com followed by 4 different time*.nist.gov servers. I expect the 64-bit box to be checking time.windows.com; if I find anything different when I get a chance to look at it, I'll report my findings. [1] http://superuser.com/questions/161759/where-do-i-find-the-internet-time-ntp-settings-in-windows-7 |
|||
msg207168 - (view) | Author: Roundup Robot (python-dev) | Date: 2014-01-02 15:43 | |
New changeset 82df66a091da by Zachary Ware in branch '3.3': Issue #20101: Allow test_monotonic to pass on Windows machines on which http://hg.python.org/cpython/rev/82df66a091da New changeset e2a1400b7db9 by Zachary Ware in branch 'default': Issue #20101: Merge with 3.3 http://hg.python.org/cpython/rev/e2a1400b7db9 |
|||
msg207186 - (view) | Author: Tim Peters (tim.peters) * | Date: 2014-01-02 20:30 | |
1. I'm sync'ing with north-america.pool.ntp.org. But the docs on my box say "Your clock is typically updated once a week", and I believe it. 2. I just ran Zach's program again, with the same Python, and _this_ time 'time' passed 25 times (as did 'monotonic'). 'time' failed 25 times in the output I pasted here before. 'clock' failed 25 times again. Here are the passing values for this run of 'time': [(0.5001208782196045, 4), (0.5001211166381836, 6), (0.5001218318939209, 5), (0.5001220703125, 10)] |
|||
msg207193 - (view) | Author: Zachary Ware (zach.ware) * | Date: 2014-01-02 22:19 | |
I ran the same test on all of the Windows buildbots, with the following results: x86 XP-4: http://buildbot.python.org/all/builders/x86%20XP-4%20custom/builds/33/steps/test/logs/stdio monotonic: good time: good clock/perf_counter: 10 failures x86 Windows7 http://buildbot.python.org/all/builders/x86%20Windows7%20custom/builds/37/steps/test/logs/stdio monotonic: good time: 24 failures clock/perf_counter: 11 failures AMD64 Windows7 SP1 http://buildbot.python.org/all/builders/AMD64%20Windows7%20SP1%20custom/builds/41/steps/test/logs/stdio All good x86 Windows Server 2003 http://buildbot.python.org/all/builders/x86%20Windows%20Server%202003%20%5BSB%5D%20custom/builds/33/steps/test/logs/stdio monotonic: good time: good clock/perf_counter: all failures AMD64 Windows Server 2008R2 http://buildbot.python.org/all/builders/AMD64%20Windows%20Server%202008%20%5BSB%5D%20custom/builds/17/steps/test/logs/stdio All good x86 Windows Server 2008R2 http://buildbot.python.org/all/builders/x86%20Windows%20Server%202008%20%5BSB%5D%20custom/builds/0/steps/test/logs/stdio All good Also, I noticed three different resolutions for monotonic: mine, Tim's, and 0.0100144 on the XP-4 bot. |
|||
msg225160 - (view) | Author: Mark Lawrence (BreamoreBoy) * | Date: 2014-08-10 19:38 | |
Is there anything else that can be done or needs doing here? |
|||
msg225161 - (view) | Author: STINNER Victor (vstinner) * | Date: 2014-08-10 20:01 | |
time.sleep() and time.monotonic() don't use the same clock. Python cannot fix Windows clocks, it's not a bug. |
History | |||
---|---|---|---|
Date | User | Action | Args |
2022-04-11 14:57:56 | admin | set | github: 64300 |
2014-08-10 20:01:25 | vstinner | set | status: open -> closed resolution: not a bug messages: + msg225161 |
2014-08-10 19:38:22 | BreamoreBoy | set | nosy:
+ BreamoreBoy messages: + msg225160 |
2014-01-02 22:19:04 | zach.ware | set | messages: + msg207193 |
2014-01-02 20:30:09 | tim.peters | set | messages: + msg207186 |
2014-01-02 15:43:31 | python-dev | set | nosy:
+ python-dev messages: + msg207168 |
2014-01-02 14:54:41 | zach.ware | set | messages: + msg207167 |
2014-01-02 14:01:59 | vstinner | set | messages: + msg207165 |
2014-01-02 13:20:07 | loewis | set | nosy:
+ loewis messages: + msg207162 |
2014-01-02 02:03:08 | tim.peters | set | messages: + msg207141 |
2014-01-01 11:42:32 | jkloth | set | nosy:
+ jkloth |
2013-12-31 21:42:32 | zach.ware | create |