Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

bpo-32025: Add time.thread_time() #4410

Merged
merged 6 commits into from
Nov 15, 2017
Merged
Show file tree
Hide file tree
Changes from 4 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
26 changes: 26 additions & 0 deletions Doc/library/time.rst
Original file line number Diff line number Diff line change
Expand Up @@ -241,6 +241,7 @@ Functions
* ``'monotonic'``: :func:`time.monotonic`
* ``'perf_counter'``: :func:`time.perf_counter`
* ``'process_time'``: :func:`time.process_time`
* ``'thread_time'``: :func:`time.thread_time`
* ``'time'``: :func:`time.time`

The result has the following attributes:
Expand Down Expand Up @@ -603,6 +604,31 @@ Functions
of the calendar date may be accessed as attributes.


.. function:: thread_time() -> float

.. index::
single: CPU time
single: processor time
single: benchmarking

Return the value (in fractional seconds) of the sum of the system and user
CPU time of the current thread. It does not include time elapsed during
sleep. It is thread-specific by definition. The reference point of the
returned value is undefined, so that only the difference between the results
of consecutive calls in the same thread is valid.

Availability: Unix systems supporting CLOCK_THREAD_CPUTIME_ID, Windows.
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I propose:

Availability: Windows, Linux, Unix systems supporting CLOCK_THREAD_CPUTIME_ID.


.. versionadded:: 3.7


.. function:: thread_time_ns() -> int

Similar to :func:`thread_time` but return time as nanoseconds.

.. versionadded:: 3.7


.. function:: time_ns() -> int

Similar to :func:`time` but returns time as an integer number of nanoseconds
Expand Down
4 changes: 4 additions & 0 deletions Doc/whatsnew/3.7.rst
Original file line number Diff line number Diff line change
Expand Up @@ -372,6 +372,10 @@ Add new clock identifiers:
the time the system has been running and not suspended, providing accurate
uptime measurement, both absolute and interval.

Added functions :func:`time.thread_time` and :func:`time.thread_time_ns`
to get per-thread CPU time measurements.
(Contributed by Antoine Pitrou in :issue:`32025`.)

unittest.mock
-------------

Expand Down
57 changes: 57 additions & 0 deletions Lib/test/test_time.py
Original file line number Diff line number Diff line change
Expand Up @@ -47,6 +47,12 @@ class _PyTime(enum.IntEnum):
)


def busy_wait(duration):
deadline = time.monotonic() + duration
while time.monotonic() < deadline:
pass


class TimeTestCase(unittest.TestCase):

def setUp(self):
Expand Down Expand Up @@ -81,6 +87,10 @@ def check_ns(sec, ns):
check_ns(time.process_time(),
time.process_time_ns())

if hasattr(time, 'thread_time'):
check_ns(time.thread_time(),
time.thread_time_ns())

if hasattr(time, 'clock_gettime'):
check_ns(time.clock_gettime(time.CLOCK_REALTIME),
time.clock_gettime_ns(time.CLOCK_REALTIME))
Expand Down Expand Up @@ -486,10 +496,57 @@ def test_process_time(self):
# on Windows
self.assertLess(stop - start, 0.020)

# process_time() should include CPU time spent in any thread
start = time.process_time()
busy_wait(0.100)
stop = time.process_time()
self.assertGreaterEqual(stop - start, 0.020) # machine busy?

t = threading.Thread(target=busy_wait, args=(0.100,))
start = time.process_time()
t.start()
t.join()
stop = time.process_time()
self.assertGreaterEqual(stop - start, 0.020) # machine busy?

info = time.get_clock_info('process_time')
self.assertTrue(info.monotonic)
self.assertFalse(info.adjustable)

def test_thread_time(self):
if not hasattr(time, 'thread_time'):
if sys.platform.startswith(('linux', 'win')):
self.fail("time.thread_time() should be available on %r"
% (sys.platform,))
else:
self.skipTest("need time.thread_time")

# thread_time() should not include time spend during a sleep
start = time.thread_time()
time.sleep(0.100)
stop = time.thread_time()
# use 20 ms because thread_time() has usually a resolution of 15 ms
# on Windows
self.assertLess(stop - start, 0.020)

# thread_time() should include CPU time spent in current thread...
start = time.thread_time()
busy_wait(0.100)
stop = time.thread_time()
self.assertGreaterEqual(stop - start, 0.020) # machine busy?
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Shouldn't it be 0.100 - 0.020 or maybe just 0.100?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please don't be too strict, or the test will fail randomly on grumpy buildbots.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The whole CPU time in those 0.1 seconds was not necessarily allocated to the current process / thread.


# ...but not in other threads
t = threading.Thread(target=busy_wait, args=(0.100,))
start = time.thread_time()
t.start()
t.join()
stop = time.thread_time()
self.assertLess(stop - start, 0.020)

info = time.get_clock_info('thread_time')
self.assertTrue(info.monotonic)
self.assertFalse(info.adjustable)

@unittest.skipUnless(hasattr(time, 'clock_settime'),
'need time.clock_settime')
def test_monotonic_settime(self):
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
Add time.thread_time()
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

And time.thread_time_ns().

117 changes: 117 additions & 0 deletions Modules/timemodule.c
Original file line number Diff line number Diff line change
Expand Up @@ -1258,6 +1258,112 @@ Process time for profiling as nanoseconds:\n\
sum of the kernel and user-space CPU time.");


#if defined(MS_WINDOWS)
#define HAVE_THREAD_TIME
static int
_PyTime_GetThreadTimeWithInfo(_PyTime_t *tp, _Py_clock_info_t *info)
{
HANDLE thread;
FILETIME creation_time, exit_time, kernel_time, user_time;
ULARGE_INTEGER large;
_PyTime_t ktime, utime, t;
BOOL ok;

thread = GetCurrentThread();
ok = GetThreadTimes(thread, &creation_time, &exit_time,
&kernel_time, &user_time);
if (!ok) {
PyErr_SetFromWindowsErr(0);
return -1;
}

if (info) {
info->implementation = "GetThreadTimes()";
info->resolution = 1e-7;
info->monotonic = 1;
info->adjustable = 0;
}

large.u.LowPart = kernel_time.dwLowDateTime;
large.u.HighPart = kernel_time.dwHighDateTime;
ktime = large.QuadPart;

large.u.LowPart = user_time.dwLowDateTime;
large.u.HighPart = user_time.dwHighDateTime;
utime = large.QuadPart;

/* ktime and utime have a resolution of 100 nanoseconds */
t = _PyTime_FromNanoseconds((ktime + utime) * 100);
*tp = t;
return 0;
}

#elif defined(HAVE_CLOCK_GETTIME) && defined(CLOCK_PROCESS_CPUTIME_ID)
#define HAVE_THREAD_TIME
static int
_PyTime_GetThreadTimeWithInfo(_PyTime_t *tp, _Py_clock_info_t *info)
{
struct timespec ts;
const clockid_t clk_id = CLOCK_THREAD_CPUTIME_ID;
const char *function = "clock_gettime(CLOCK_THREAD_CPUTIME_ID)";

if (clock_gettime(clk_id, &ts) == 0) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I suggest to invert the test to return early on error.

if (info) {
struct timespec res;
info->implementation = function;
info->monotonic = 1;
info->adjustable = 0;
if (clock_getres(clk_id, &res)) {
PyErr_SetFromErrno(PyExc_OSError);
return -1;
}
info->resolution = res.tv_sec + res.tv_nsec * 1e-9;
}

if (_PyTime_FromTimespec(tp, &ts) < 0) {
return -1;
}
return 0;
}
PyErr_SetFromErrno(PyExc_OSError);
return -1;
}
#endif

#ifdef HAVE_THREAD_TIME
static PyObject *
time_thread_time(PyObject *self, PyObject *unused)
{
_PyTime_t t;
if (_PyTime_GetThreadTimeWithInfo(&t, NULL) < 0) {
return NULL;
}
return _PyFloat_FromPyTime(t);
}

PyDoc_STRVAR(thread_time_doc,
"thread_time() -> float\n\
\n\
Thread time for profiling: sum of the kernel and user-space CPU time.");

static PyObject *
time_thread_time_ns(PyObject *self, PyObject *unused)
{
_PyTime_t t;
if (_PyTime_GetThreadTimeWithInfo(&t, NULL) < 0) {
return NULL;
}
return _PyTime_AsNanosecondsObject(t);
}

PyDoc_STRVAR(thread_time_ns_doc,
"thread_time() -> int\n\
\n\
Thread time for profiling as nanoseconds:\n\
sum of the kernel and user-space CPU time.");
#endif


static PyObject *
time_get_clock_info(PyObject *self, PyObject *args)
{
Expand Down Expand Up @@ -1311,6 +1417,13 @@ time_get_clock_info(PyObject *self, PyObject *args)
return NULL;
}
}
#ifdef HAVE_THREAD_TIME
else if (strcmp(name, "thread_time") == 0) {
if (_PyTime_GetThreadTimeWithInfo(&t, &info) < 0) {
return NULL;
}
}
#endif
else {
PyErr_SetString(PyExc_ValueError, "unknown clock");
return NULL;
Expand Down Expand Up @@ -1519,6 +1632,10 @@ static PyMethodDef time_methods[] = {
{"monotonic_ns", time_monotonic_ns, METH_NOARGS, monotonic_ns_doc},
{"process_time", time_process_time, METH_NOARGS, process_time_doc},
{"process_time_ns", time_process_time_ns, METH_NOARGS, process_time_ns_doc},
#ifdef HAVE_THREAD_TIME
{"thread_time", time_thread_time, METH_NOARGS, thread_time_doc},
{"thread_time_ns", time_thread_time_ns, METH_NOARGS, thread_time_ns_doc},
#endif
{"perf_counter", time_perf_counter, METH_NOARGS, perf_counter_doc},
{"perf_counter_ns", time_perf_counter_ns, METH_NOARGS, perf_counter_ns_doc},
{"get_clock_info", time_get_clock_info, METH_VARARGS, get_clock_info_doc},
Expand Down