[issue19999] test_monotonic fails on x86 OpenIndiana

[STINNER Victor]

STINNER Victor added the comment:

 but 0.0156001 isn't close enough to 0.015625 for rounding errors to be at 
 all a plausible explanation for why it's so strange.

0.0156001 is close to 0.0156, and this number cannot be representated exactly 
in binary:

 (0.0156).hex()
'0x1.ff2e48e8a71dep-7'

C code used by Python:

GetSystemTimeAdjustment(timeAdjustment, timeIncrement,
isTimeAdjustmentDisabled);
info-resolution = timeIncrement * 1e-7;

(And yes, 0.0156001 is surprising, I also expected 1/64, 0.015625)

--

___
Python tracker rep...@bugs.python.org
http://bugs.python.org/issue1
___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue19999] test_monotonic fails on x86 OpenIndiana

[STINNER Victor]

STINNER Victor added the comment:

 GetSystemTimeAdjustment is not the function to look at.

This sentence comes from 
http://stackoverflow.com/questions/7685762/windows-7-timing-functions-how-to-use-getsystemtimeadjustment-correctly
 which describes the wall clock (GetSystemTimeAsFileTime), not the monotonic 
clock (GetTickCount[64]).

GetTickCount[64] resolution cannot be better than 1 ms because its C structure 
has a resolution of 1 ms...

But I don't know any other *monotonic* clock with a better resolution.

Python 3.3 provides time.perf_counter(): clock with the highest available 
resolution to measure a short duration. I added this function because of 
Windows, to give access to QueryPerformanceCounter().

@Tim: This issue is closed. If you believe that Python time functions are buggy 
on windows, which is quite possible, please open a *new* issue. (This issue was 
specific to OpenIndiana buildbot which looks to be ill.)

The C function pygettimeofday() which is used by time.time() and 
time.get_clock_info() uses GetSystemTimeAsFileTime() and 
GetSystemTimeAdjustment(). According to the article, there is a bug.

--

___
Python tracker rep...@bugs.python.org
http://bugs.python.org/issue1
___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue19999] test_monotonic fails on x86 OpenIndiana

[Zachary Ware]

Zachary Ware added the comment:

That's weird.  I ran the same test on the same computer with an installed 
64-bit 3.3.2, and got the same results (70+% failure).  I just ran the same 
test on a different computer (32-bit Windows 7), and also got the same results 
with both 3.4.0b1+ and 3.3.2 (installed).

FTR:
 time.get_clock_info('monotonic')
namespace(adjustable=False, implementation='GetTickCount64()', monotonic=True, 
resolution=0.0156000999)

I believe it's the same for all four Pythons tested.

Shall I open a new issue for this, or is it related enough to stay here? :)

--

___
Python tracker rep...@bugs.python.org
http://bugs.python.org/issue1
___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue19999] test_monotonic fails on x86 OpenIndiana

[Tim Peters]

Tim Peters added the comment:

Hmm.  One obvious difference on my box:

Python 3.3.2 (v3.3.2:d047928ae3f6, May 16 2013, 00:03:43) [MSC v.1600 32 bit 
(Intel)] on win32
 time.get_clock_info('monotonic')
namespace(adjustable=False, implementation='GetTickCount64()', monotonic=True, 
resolution=0.015625)

So the resolution here is exactly 1/64.  If that's truly the resolution, then 
all the results I'll see are exactly representable as Python floats.

The resolution you see (0.0156000999) looks bizarre.  Not because of 
the trailing nines, but because 0.0156001 doesn't appear to have any natural 
hardware or software meaning in decimal or binary.

That said, I see we get the resolution from GetSystemTimeAdjustment.  I don't 
understand the Windows time functions, but also don't see anything in the MSDN 
docs to suggest that the results from GetSystemTimeAdjustment should have 
anything to do with the resolution of GetTickCount64.  But maybe they do - LOL 
;-)

One other point:  we have lots of code of the form:

info-resolution = timeIncrement * 1e-7;

That is, we multiply some integer type by a double _negative_ power of 10.  All 
such code is needlessly inaccurate:  no negative power of 10 is exactly 
representable as a double, so we suffer a rounding error in representing 1e-7, 
and then another rounding error from the multiplication.  It's trivial to 
reduce the grand total to one rounding error instead, by rewriting as:

info-resolution = timeIncrement / 1e7;

But these rounding errors are too tiny to account for the difference between, 
e.g., 0.499000107102 and 0.5.

I don't conclude that we don't know what we're doing, but I bet we don't really 
understand what Windows is doing ;-)

--

___
Python tracker rep...@bugs.python.org
http://bugs.python.org/issue1
___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue19999] test_monotonic fails on x86 OpenIndiana

[STINNER Victor]

STINNER Victor added the comment:

For more info on time, you can refer to the PEP 418.

I may be interesting to add sleep to time.get_clock_info(). time.sleep()
uses WaitForSingleObject() on windows. It may use internally a different
clock with a different resolution than time.monoyonic (GetTickCount). The
PEP says WaitForSingleObject(): use the same timer than GetTickCount()
with the same precision.

I don't think that it's very useful to investigate the rounding issue on
Windows. The resolution of Windows clocks is very coarse (15 ms, 10^-2)
compared to Unix clocks (usually a few nanoseconds, 10^-9)... I changed
recently the unit test to check if a sleep of 0.5 seconds gives a time
delta of at least 0.5 seconds. The minimum delta can be set to 0.45 sec
with a comment refering to this issue.

--

___
Python tracker rep...@bugs.python.org
http://bugs.python.org/issue1
___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue19999] test_monotonic fails on x86 OpenIndiana

[Tim Peters]

Tim Peters added the comment:

@haypo, I've read the PEP and it has great ideas.  What I'm wondering is 
whether they've been implemented correctly in the relevant cases on Windows 
here.  That Zach see a resolution of 0.0156001 on Windows isn't plausibly a 
question of rounding errors:  that value appears to be insane.  Yes, it's 
vaguely close to the 0.015625 I see, but the value I see _is_ sane (being 
exactly 1/64) - but 0.0156001 isn't close enough to 0.015625 for rounding 
errors to be at all a plausible explanation for why it's so strange.

--

___
Python tracker rep...@bugs.python.org
http://bugs.python.org/issue1
___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue19999] test_monotonic fails on x86 OpenIndiana

[Tim Peters]

Tim Peters added the comment:

FYI, this person seems to have made a career ;-) of making sense of the Windows 
time functions:

http://stackoverflow.com/questions/7685762/windows-7-timing-functions-how-to-use-getsystemtimeadjustment-correctly

and their site:

http://www.windowstimestamp.com/description

Bottom line is that it's messy as everything else on Windows :-(  They claim, 
among other things:

- GetSystemTimeAdjustment is not the function to look at.

- The undocumented NtQueryTimerResolution() is the function to look at.

- Time Adjustment: 0.0156001 clearly identifies windows VISTA or higher with 
HPET and/or constant/invariant TSC on your system.

Screw it - I'm gonna go shovel more snow ;-)

--

___
Python tracker rep...@bugs.python.org
http://bugs.python.org/issue1
___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue19999] test_monotonic fails on x86 OpenIndiana

[Zachary Ware]

Zachary Ware added the comment:

I think the minimum bound for dt could stand to be relaxed very slightly, 
here's some results from my 64-bit Win7 box running 32-bit Python:

3.4.0b1 (default:eae6966d9734+, Dec 21 2013, 15:47:14) [MSC v.1600 32 bit 
(Intel)]
sys.getwindowsversion(major=6, minor=1, build=7601, platform=2, 
service_pack='Service Pack 1')
Running:
import time
import sys
print(sys.version)
print(sys.getwindowsversion())

with open(__file__) as file:
print('Running:')
print(file.read())

for i in range(10):
# copied from test_monotonic, with regular assert and added prints
t1 = time.monotonic()
time.sleep(0.5)
t2 = time.monotonic()
dt = t2 - t1
assert t2  t1
print(i, t1, t2, dt, sep='\t')
print('  assertion', 'passed' if 0.5 = dt = 1.0 else 'failed')

0   243323.5420002  243324.041  0.498999816064
  assertion failed
1   243324.041  243324.54   0.499000107102
  assertion failed
2   243324.54   243325.0390002  0.499000107102
  assertion failed
3   243325.0390002  243325.5390002  0.5
  assertion passed
4   243325.5390002  243326.038  0.498999816064
  assertion failed
5   243326.038  243326.537  0.499000107102
  assertion failed
6   243326.537  243327.036  0.498999816064
  assertion failed
7   243327.036  243327.535  0.499000107102
  assertion failed
8   243327.535  243328.035  0.5
  assertion passed
9   243328.035  243328.534  0.499000107102
  assertion failed


I suspect there's some rounding going on somewhere, making dt usually about 
0.499, not 0.5.  Relaxing the condition to '0.498  dt  1.0' should be 
adequate, since I don't think a thousandth of a second only part of the time is 
enough to say there's a behavior issue.

I haven't seen this fail on any buildbots, but I suspect most of them are just 
loaded a bit heavier than my laptop is when I see this.

--
nosy: +zach.ware

___
Python tracker rep...@bugs.python.org
http://bugs.python.org/issue1
___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue19999] test_monotonic fails on x86 OpenIndiana

[Tim Peters]

Tim Peters added the comment:

@Zach, it would be nice to know more about this.  I tried your little program 
on a desktop box, 32-bit Windows Vista, Python 3.3.2, but I boosted the loop 
count to 10,000.  So it ran well over an hour, with a wide variety of other 
loads (from 0 to 4 (of 4) cores busy).  `dt` was never less than 0.5.  It was 
exactly 0.5 9,997(!) times, and a little larger than 0.5 the remaining 3 times. 
 Yes, I was surprised too ;-)

--
nosy: +tim.peters

___
Python tracker rep...@bugs.python.org
http://bugs.python.org/issue1
___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue19999] test_monotonic fails on x86 OpenIndiana

[Christian Heimes]

New submission from Christian Heimes:

I have seen this failure multiple times.

http://buildbot.python.org/all/builders/x86%20OpenIndiana%203.x/builds/7353/steps/test/logs/stdio

==
FAIL: test_monotonic (test.test_time.TimeTestCase)
--
Traceback (most recent call last):
  File 
/export/home/buildbot/32bits/3.x.cea-indiana-x86/build/Lib/test/test_time.py, 
line 387, in test_monotonic
self.assertAlmostEqual(dt, 0.5, delta=0.2)
AssertionError: 0.8012567944824696 != 0.5 within 0.2 delta

--

--
assignee: haypo
components: Tests
keywords: buildbot
messages: 206344
nosy: christian.heimes, haypo
priority: low
severity: normal
stage: test needed
status: open
title: test_monotonic fails on x86 OpenIndiana
type: behavior
versions: Python 3.4

___
Python tracker rep...@bugs.python.org
http://bugs.python.org/issue1
___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue19999] test_monotonic fails on x86 OpenIndiana

[Roundup Robot]

Roundup Robot added the comment:

New changeset 4864c0b914ae by Victor Stinner in branch '3.3':
Close #1: tolerate coarse time when testing time.monotonic() on very
http://hg.python.org/cpython/rev/4864c0b914ae

New changeset a34582c53911 by Victor Stinner in branch 'default':
(Merge 3.3) Close #1: tolerate coarse time when testing time.monotonic() on
http://hg.python.org/cpython/rev/a34582c53911

--
nosy: +python-dev
resolution:  - fixed
stage: test needed - committed/rejected
status: open - closed

___
Python tracker rep...@bugs.python.org
http://bugs.python.org/issue1
___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue19999] test_monotonic fails on x86 OpenIndiana

[STINNER Victor]

STINNER Victor added the comment:

Hum, there is something wrong with this buildbot!

http://buildbot.python.org/all/builders/x86%20OpenIndiana%203.3/builds/1266/steps/test/logs/stdio

==
FAIL: test_monotonic (test.test_time.TimeTestCase)
--
Traceback (most recent call last):
  File 
/export/home/buildbot/32bits/3.3.cea-indiana-x86/build/Lib/test/test_time.py, 
line 379, in test_monotonic
self.assertTrue(0.5 = dt = 1.0, dt)
AssertionError: False is not true : 2.2977897822856903

--

___
Python tracker rep...@bugs.python.org
http://bugs.python.org/issue1
___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com