Implementation of the PEP 418

@malemburg

BPO	14428
Nosy	@malemburg, @pitrou, @vstinner
Files	perf_counter_process_time-2.patch 667541bb315c.diff 4255e3c4daf2.diff

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = <Date 2012-06-04.23:09:50.912>
created_at = <Date 2012-03-28.01:11:31.262>
labels = ['type-feature', 'library']
title = 'Implementation of the PEP 418'
updated_at = <Date 2012-06-05.17:28:52.432>
user = 'https://github.com/vstinner'

bugs.python.org fields:

activity = <Date 2012-06-05.17:28:52.432>
actor = 'pitrou'
assignee = 'none'
closed = True
closed_date = <Date 2012-06-04.23:09:50.912>
closer = 'vstinner'
components = ['Library (Lib)']
creation = <Date 2012-03-28.01:11:31.262>
creator = 'vstinner'
dependencies = []
files = ['25265', '25396', '25397']
hgrepos = ['118']
issue_num = 14428
keywords = ['patch']
message_count = 44.0
messages = ['156960', '156975', '157378', '157387', '157388', '157389', '157400', '157409', '157410', '157411', '157412', '157468', '157469', '157516', '157989', '158186', '158187', '158224', '158233', '158241', '158416', '158545', '158558', '158577', '158607', '158668', '158715', '159550', '159552', '159554', '159558', '159591', '159634', '159635', '159639', '159653', '159657', '159659', '159662', '159669', '161946', '162305', '162332', '162359']
nosy_count = 6.0
nosy_names = ['lemburg', 'pitrou', 'vstinner', 'Arfrever', 'neologix', 'python-dev']
pr_nums = []
priority = 'normal'
resolution = 'fixed'
stage = None
status = 'closed'
superseder = None
type = 'enhancement'
url = 'https://bugs.python.org/issue14428'
versions = ['Python 3.3']

Attached patch implements the PEP-418: add time.monotonic() and time.hires(). In practice, it replaces time.steady() by time.hires() and time.steady(strict=True) by time.monotonic().

Tiny review.

Two more details:

since it's relatively straightforward to cache the last value returned using a static variable, it might be interesting to use this to make sure that the values returned are indeed monotonic
I'm not a native speaker, but hires name bothers me a bit, I'd prefer highres (see for example http://www.kernel.org/doc/Documentation/timers/highres.txt, the highres kernel parameter and patch-set name), or maybe hrtime

Updated patch:

Implement time.get_clock_info()
time.monotonic() never fails: fallback to time.time() if needed

TODO: time.monotonic() must use GetTickCount64() or GetTickCount() on Windows, with a detection of integer overflow on GetTickCount().

Patch version 3:

fix compilation on non-Linux (e.g. on FreeBSD and OpenBSD)
time.monotonic() uses GetTickCount/GetTickCount64 on Windows
clock_getres() fills the accuracy field instead of the resolution field of time.get_clock_info()

Clock information on different operating systems.

Linux (Fedora 16) on x86_64:

>>> pprint.pprint(time.get_clock_info('clock'))
{'accuracy': 1e-06,
 'function': 'clock()',
 'is_adjusted': False,
 'is_monotonic': True,
 'resolution': 1e-06}
>>> pprint.pprint(time.get_clock_info('highres'))
{'accuracy': 1e-09,
 'function': 'clock_gettime(CLOCK_MONOTONIC_RAW)',
 'is_adjusted': False,
 'is_monotonic': True,
 'resolution': 1e-09}
>>> pprint.pprint(time.get_clock_info('monotonic'))
{'accuracy': 1e-09,
 'function': 'clock_gettime(CLOCK_MONOTONIC_RAW)',
 'is_adjusted': False,
 'is_monotonic': True,
 'resolution': 1e-09}
>>> pprint.pprint(time.get_clock_info('time'))
{'accuracy': 1e-09,
 'function': 'clock_gettime(CLOCK_REALTIME)',
 'is_adjusted': True,
 'is_monotonic': False,
 'resolution': 1e-09}

FreeBSD 8.2 on x86_64:

>>> pprint.pprint(time.get_clock_info('clock'))
{'accuracy': 0.0078125,
 'function': 'clock()',
 'is_adjusted': False,
 'is_monotonic': True,
 'resolution': 0.0078125}
>>> pprint.pprint(time.get_clock_info('highres')) 
{'accuracy': 1.1000000000000001e-08,
 'function': 'clock_gettime(CLOCK_MONOTONIC)',
 'is_monotonic': True,
 'resolution': 1e-09}
>>> pprint.pprint(time.get_clock_info('monotonic'))
{'accuracy': 1.1000000000000001e-08,
 'function': 'clock_gettime(CLOCK_MONOTONIC)',
 'is_monotonic': True,
 'resolution': 1e-09}
>>> pprint.pprint(time.get_clock_info('time'))
{'accuracy': 1.1000000000000001e-08,
 'function': 'clock_gettime(CLOCK_REALTIME)',
 'is_adjusted': True,
 'is_monotonic': False,
 'resolution': 1e-09}

OpenBSD on x86_64:

>>> pprint.pprint(time.get_clock_info('clock'))  
{'accuracy': 0.01,
 'function': 'clock()',
 'is_adjusted': False,
 'is_monotonic': True,
 'resolution': 0.01}
>>> pprint.pprint(time.get_clock_info('highres'))
{'accuracy': 0.01,
 'function': 'clock_gettime(CLOCK_MONOTONIC)',
 'is_monotonic': True,
 'resolution': 1e-09}
>>> pprint.pprint(time.get_clock_info('monotonic'))
{'accuracy': 0.01,
 'function': 'clock_gettime(CLOCK_MONOTONIC)',
 'is_monotonic': True,
 'resolution': 1e-09}
>>> pprint.pprint(time.get_clock_info('time'))
{'accuracy': 0.01,
 'function': 'clock_gettime(CLOCK_REALTIME)',
 'is_adjusted': True,
 'is_monotonic': False,
 'resolution': 1e-09}

Python 32 bits on Windows 64 bits:

>>> pprint.pprint(time.get_clock_info('clock'))
{'accuracy': 1e-08,
 'function': 'QueryPerformanceCounter()',
 'is_adjusted': False,
 'is_monotonic': True,
 'resolution': 1e-08}
>>> pprint.pprint(time.get_clock_info('highres'))
{'accuracy': 1e-08,
 'function': 'QueryPerformanceCounter()',
 'is_adjusted': False,
 'is_monotonic': True,
 'resolution': 1e-08}
>>> pprint.pprint(time.get_clock_info('monotonic'))
{'accuracy': 0.015600099999999999,
 'function': 'GetTickCount()',
 'is_adjusted': False,
 'is_monotonic': True,
 'resolution': 0.001}
>>> pprint.pprint(time.get_clock_info('time'))
{'accuracy': 0.015600099999999999,
 'function': 'GetSystemTimeAsFileTime()',
 'is_adjusted': True,
 'is_monotonic': False,
 'resolution': 1e-07}

Some remarks:

these 4 platforms provide a monotonic clock
these 4 platforms provide the accurary of the 4 clocks (it looks like Linux is cheating)
on OpenBSD, time.highres() resolution is not so "high". It has only an accuracy of 10 ms.
as expected, the accuracy is very different from the resolution in some cases (ex: 0.0156 vs 1e-07 for time.time() on Windows)

Solaris on x86_64:

>>> pprint.pprint(time.get_clock_info('clock'))
{'accuracy': 1e-06,
 'function': 'clock()',
 'is_adjusted': False,
 'is_monotonic': True,
 'resolution': 1e-06}
>>> pprint.pprint(time.get_clock_info('highres'))
{'accuracy': 2e-09,
 'function': 'clock_gettime(CLOCK_HIGHRES)',
 'is_adjusted': False,
 'is_monotonic': True,
 'resolution': 1e-09}
>>> pprint.pprint(time.get_clock_info('monotonic'))
{'accuracy': 2e-09,
 'function': 'clock_gettime(CLOCK_HIGHRES)',
 'is_adjusted': False,
 'is_monotonic': True,
 'resolution': 1e-09}
>>> pprint.pprint(time.get_clock_info('time'))
{'accuracy': 0.01,
 'function': 'clock_gettime(CLOCK_REALTIME)',
 'is_adjusted': True,
 'is_monotonic': False,
 'resolution': 1e-09}

TODO (PEP-418-3.patch):

Use CLOCK_HIGHRES on Solaris
Maybe implement gethrtime() for Solaris

Hi Victor,

I think you need to reconsider the time.steady() name you're using
in the PEP. For practical purposes, it's better to call it
time.monotonic() and only make the function available if the OS provides
a monotonic clock.

The fallback to time.time() is not a good idea, since then the programmer
has to check whether the timer really provides the features she's after
every time it gets used.

Regardless of this functional problem, I'm also not sure what you want
to imply by the term "steady". A steady beat would mean that the timer
never stops and keeps a constant pace, but that's not the case for
the timers you're using to implement time.steady(). If you're after
a mathematical term, "continuous" would be a better term, but
again, time.time() is not always continuous.

Instead of trying to tweak all the different clocks and timers into
a single function, wouldn't it be better to expose each kind as a
different function and then let the programmer decide which fits
best ?!

BTW: Thanks for the research you've done on the different clocks and
timers. That's very useful information.

Thanks,

Marc-Andre Lemburg
eGenix.com

2012-04-03: Python Meeting Duesseldorf today

::: Try our new mxODBC.Connect Python Database Interface for free ! ::::

eGenix.com Software, Skills and Services GmbH Pastor-Loeh-Str.48
D-40764 Langenfeld, Germany. CEO Dipl.-Math. Marc-Andre Lemburg
Registered at Amtsgericht Duesseldorf: HRB 46611
http://www.egenix.com/company/contact/

I think you need to reconsider the time.steady() name you're using
in the PEP. For practical purposes, it's better to call it
time.monotonic()

I opened a new thread on python-dev to discuss this topic.

and only make the function available if the OS provides
a monotonic clock.

Oh, I should explain this choice in the PEP. Basically, the idea is to
provide a best-effort portable function.

The fallback to time.time() is not a good idea, since then the programmer
has to check whether the timer really provides the features she's after
every time it gets used.

Nope, time.get_clock_info('steady') does not change at runtime. So it
can only be checked once.

Instead of trying to tweak all the different clocks and timers into
a single function, wouldn't it be better to expose each kind as a
different function and then let the programmer decide which fits
best ?!

This is a completly different approach. It should be discussed on
python-dev, not in the bug tracker please. I think that Python can
help the developer to write portable code by providing high-level
functions because clock properties are well known (e.g. see
time.get_clock_info).

BTW: Thanks for the research you've done on the different clocks and
timers. That's very useful information.

You're welcome.

STINNER Victor wrote:

STINNER Victor <victor.stinner@gmail.com> added the comment:

> I think you need to reconsider the time.steady() name you're using
> in the PEP. For practical purposes, it's better to call it
> time.monotonic()

I opened a new thread on python-dev to discuss this topic.

> and only make the function available if the OS provides
> a monotonic clock.

Oh, I should explain this choice in the PEP. Basically, the idea is to
provide a best-effort portable function.

> The fallback to time.time() is not a good idea, since then the programmer
> has to check whether the timer really provides the features she's after
> every time it gets used.

Nope, time.get_clock_info('steady') does not change at runtime. So it
can only be checked once.

With "every time" I meant: in every application you use the function.
That pretty much spoils the idea of a best effort portable function.

It's better to use a try-except to test for availability of
functions than to have to (remember to) call a separate function
to find out the characteristics of the best effort approach.

> Instead of trying to tweak all the different clocks and timers into
> a single function, wouldn't it be better to expose each kind as a
> different function and then let the programmer decide which fits
> best ?!

This is a completly different approach. It should be discussed on
python-dev, not in the bug tracker please. I think that Python can
help the developer to write portable code by providing high-level
functions because clock properties are well known (e.g. see
time.get_clock_info).

Fair enough.

BTW: Are aware of the existing systimes.py module in pybench,
which already provides interfaces to high resolution timers usable
for benchmarking in a portable way ? Perhaps worth mentioning in
the PEP.

Patch version 4:

Rename time.monotonic() to time.steady()
Don't use CLOCK_MONOTONIC_RAW but CLOCK_MONOTONIC for time.highres() and time.steady()
Use CLOCK_HIGHRES, useful on Solaris
Rewrite time.highres() and time.steady() documentation

BTW: Are aware of the existing systimes.py module in pybench,
which already provides interfaces to high resolution timers usable
for benchmarking in a portable way ? Perhaps worth mentioning in
the PEP.

Nope, I didn't know it. It mentioned it in the PEP.

Patch version 5, updated to the last version of the PEP:

drop time.highres()
time.monotonic() is always monotonic but it not always available
add a test on time.monotonic() setting the system clock (jump backward wtih a delta of 1 hour)

+#if defined(linux) || defined(__linux) || defined(linux)

Hum, a better check should be done in configure and/or a macro like MS_WINDOWS should be added.

Version 6: simplify the code handling GetTickCounter() integer overflow. We don't need a has_last_ticks variable.

New changeset 1255cac63dfc by Victor Stinner in branch 'default':
Issue bpo-14428: Rewrite test_process_time_threads() test
http://hg.python.org/cpython/rev/1255cac63dfc

"The test is a bit too optimistic: a thread is looping for 0.2s, and the test checks that the process time (user + system) increased of at least 0.1s. If the thread is preempted, there's a high chance you won't get even as low as 0.1s."

Hum, the problem is maybe that the thread is preempted, but the first problem is that the test considers that time.process_time() uses seconds.

I rewrote the test to make it more reliable.

Hum, the problem is maybe that the thread is preempted, but the first
problem is that the test considers that time.process_time() uses seconds.

Hum, what?
You mean that process_time() doesn't return seconds?

There are many sporadic failures on the buildbots:

======================================================================
FAIL: test_process_time_threads (test.test_time.TimeTestCase)
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/usr/home/buildbot/buildarea/3.x.krah-freebsd/build/Lib/test/test_time.py", line 441, in test_process_time_threads
    self.assertGreaterEqual(t2 - t1, busy)
AssertionError: 0.01249799999999368 not greater than or equal to 0.013093999999966854

New changeset 0bdf0727ee29 by Victor Stinner in branch 'default':
Issue bpo-14428: Make test_process_time_threads() less strict
http://hg.python.org/cpython/rev/0bdf0727ee29

New changeset ad3d6010379b by Victor Stinner in branch 'default':
Issue bpo-14428: Remove test_process_time_threads() from test_time
http://hg.python.org/cpython/rev/ad3d6010379b

You mean that process_time() doesn't return seconds?

Yes, dt is not a number of seconds in the following example:

t1=time.process_time(); (...); t2=time.process_time(); dt=t2-t1

I see two options: either increase the total running time,
to make it really likely you'll get a chance to run
(or decrase the lower threshold), or use times(2), and
check the result against that (does Windows have such a syscall?).

I wrote the test to check if time.process_time() measures the total CPU of the process, and not the CPU time of only the current thread.

I'm tired of this PEP, so I just removed the test. I don't think that it is really interesting and it looks difficult to write a reliable test.

Yes, dt is not a number of seconds in the following example:

t1=time.process_time(); (...); t2=time.process_time(); dt=t2-t1

OK, so what is it then?
It's not written anywhere - neither in the PEP nor in the
documentation - and it should.

Furthermore:
"""
$ cat /tmp/test_ptime.py
import sys
import time

rt = time.time()
pt = time.process_time()

for i in range(int(sys.argv[1])):
    pass

print("real time: %f" % (time.time() - rt))
print("process time: %f" % (time.process_time() - pt))
$ ./python /tmp/test_ptime.py 100000
real time: 0.168570
process time: 0.168425
"""

It really looks like seconds to me, definitely not jiffies ;-)
Also, I've had a quick look at the code, and ISTM that it does indeed
return seconds.

I wrote the test to check if time.process_time() measures the total CPU of
the process, and not the CPU time of only the current thread.

I'm tired of this PEP, so I just removed the test. I don't think that it is
really interesting and it looks difficult to write a reliable test.

Hum, right now, the only process_time test I see is test_process_time,
which just checks that a sleep almost doesn't consume "process time",
which is a bit light.

"""
# Use a factor of 0.75 because time.process_time() is maybe not precise
self.assertGreaterEqual(t2 - t1, busy * 0.75)
"""

It's not that process_time() is not precise (I assume you mean accurate ;-).
It's just that since it measures CPU time (user+system), it depends on
the scheduling: in fact, if you have let's say a real-time priority
task running at the same time, on a uniprocessor system, the thread
could in theory not even get a chance to run, which would yield a CPU
time of 0: that would still be accurate.

It really looks like seconds to me, definitely not jiffies ;-)

time.process_time() uses maybe "seconds" on Linux, but it doesn't include time elapsed during sleep. See the test:

    def test_process_time(self):
        start = time.process_time()
        time.sleep(0.1)
        stop = time.process_time()
        self.assertLess(stop - start, 0.01)

According to Wikipedia: "Since 1967, the second has been defined to be: the duration of 9,192,631,770 periods of the radiation corresponding to the transition between the two hyperfine levels of the ground state of the caesium 133 atom."

The caesium 133 atom is not sleeping while your process is sleeping, so you cannot say the time.process_time() uses second. Do you see what I mean?

@neologix

I'm closing again this issue.

@neologix: Please open a new issue if you disagree with me on the definition of "seconds" for time.process_time().

@neologix

I'm closing again this issue.

@neologix: Please open a new issue if you disagree with me on the definition of "seconds" for time.process_time().

I won't reopen, but I still disagree with your definition.
process_time() returns second, as does the Unix 'time' command return:

"""
$ time sleep 1

real 0m1.014s
user 0m0.000s
sys 0m0.000s
"""

AFAICT, process_time() returns user + sys. Since the unit of those two
fields are second, the value returned is in second. I doesn't include
time spent in 'S'/'D'/whatever time, but it's still seconds.

I don't know what you two are arguing about, since the process_time() doc says "Return the value (in fractional seconds) of the sum of the system and user CPU time of the current process".

(while I'm not sure what "fractional" seconds are, they are probably seconds in the first place :-))

Navigation Menu

Repository navigation

Implementation of the PEP 418 #58636

Thanks,

20 remaining items

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Implementation of the PEP 418 #58636

Description

Activity

vstinner commented on Mar 28, 2012

neologix commented on Mar 28, 2012

vstinner commented on Apr 2, 2012

vstinner commented on Apr 2, 2012

vstinner commented on Apr 2, 2012

vstinner commented on Apr 2, 2012

malemburg commented on Apr 3, 2012

Thanks,

vstinner commented on Apr 3, 2012

malemburg commented on Apr 3, 2012

vstinner commented on Apr 3, 2012

vstinner commented on Apr 3, 2012

vstinner commented on Apr 4, 2012

vstinner commented on Apr 4, 2012

vstinner commented on Apr 4, 2012

20 remaining items

python-dev commented on Apr 29, 2012

vstinner commented on Apr 29, 2012

neologix commented on Apr 29, 2012

pitrou commented on Apr 29, 2012

python-dev commented on Apr 29, 2012

python-dev commented on Apr 29, 2012

vstinner commented on Apr 29, 2012

neologix commented on Apr 30, 2012

vstinner commented on May 30, 2012

vstinner commented on Jun 4, 2012

neologix commented on Jun 5, 2012

pitrou commented on Jun 5, 2012

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions