bpo-36575: lsprof: Use _PyTime_GetPerfCounter() (GH-8378)

This commit is contained in:
Inada Naoki 2019-04-11 19:11:46 +09:00 committed by GitHub
parent b3c92c6ae9
commit 536a35b3f1
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
2 changed files with 40 additions and 86 deletions

View File

@ -0,0 +1,4 @@
The ``_lsprof`` module now uses internal timer same to ``time.perf_counter()`` by default.
``gettimeofday(2)`` was used on Unix. New timer has better resolution on most Unix
platforms and timings are no longer impacted by system clock updates since ``perf_counter()``
is monotonic. Patch by Inada Naoki.

View File

@ -2,62 +2,6 @@
#include "frameobject.h"
#include "rotatingtree.h"
/*** Selection of a high-precision timer ***/
#ifdef MS_WINDOWS
#include <windows.h>
static long long
hpTimer(void)
{
LARGE_INTEGER li;
QueryPerformanceCounter(&li);
return li.QuadPart;
}
static double
hpTimerUnit(void)
{
LARGE_INTEGER li;
if (QueryPerformanceFrequency(&li))
return 1.0 / li.QuadPart;
else
return 0.000001; /* unlikely */
}
#else /* !MS_WINDOWS */
#ifndef HAVE_GETTIMEOFDAY
#error "This module requires gettimeofday() on non-Windows platforms!"
#endif
#include <sys/resource.h>
#include <sys/times.h>
static long long
hpTimer(void)
{
struct timeval tv;
long long ret;
#ifdef GETTIMEOFDAY_NO_TZ
gettimeofday(&tv);
#else
gettimeofday(&tv, (struct timezone *)NULL);
#endif
ret = tv.tv_sec;
ret = ret * 1000000 + tv.tv_usec;
return ret;
}
static double
hpTimerUnit(void)
{
return 0.000001;
}
#endif /* MS_WINDOWS */
/************************************************************/
/* Written by Brett Rosen and Ted Czotter */
@ -66,8 +10,8 @@ struct _ProfilerEntry;
/* represents a function called from another function */
typedef struct _ProfilerSubEntry {
rotating_node_t header;
long long tt;
long long it;
_PyTime_t tt;
_PyTime_t it;
long callcount;
long recursivecallcount;
long recursionLevel;
@ -77,8 +21,8 @@ typedef struct _ProfilerSubEntry {
typedef struct _ProfilerEntry {
rotating_node_t header;
PyObject *userObj; /* PyCodeObject, or a descriptive str for builtins */
long long tt; /* total time in this entry */
long long it; /* inline time in this entry (not in subcalls) */
_PyTime_t tt; /* total time in this entry */
_PyTime_t it; /* inline time in this entry (not in subcalls) */
long callcount; /* how many times this was called */
long recursivecallcount; /* how many times called recursively */
long recursionLevel;
@ -86,8 +30,8 @@ typedef struct _ProfilerEntry {
} ProfilerEntry;
typedef struct _ProfilerContext {
long long t0;
long long subt;
_PyTime_t t0;
_PyTime_t subt;
struct _ProfilerContext *previous;
ProfilerEntry *ctxEntry;
} ProfilerContext;
@ -114,41 +58,46 @@ static PyTypeObject PyProfiler_Type;
/*** External Timers ***/
#define DOUBLE_TIMER_PRECISION 4294967296.0
static PyObject *empty_tuple;
static long long CallExternalTimer(ProfilerObject *pObj)
static _PyTime_t CallExternalTimer(ProfilerObject *pObj)
{
long long result;
PyObject *o = PyObject_Call(pObj->externalTimer, empty_tuple, NULL);
PyObject *o = _PyObject_CallNoArg(pObj->externalTimer);
if (o == NULL) {
PyErr_WriteUnraisable(pObj->externalTimer);
return 0;
}
_PyTime_t result;
int err;
if (pObj->externalTimerUnit > 0.0) {
/* interpret the result as an integer that will be scaled
in profiler_getstats() */
result = PyLong_AsLongLong(o);
err = _PyTime_FromNanosecondsObject(&result, o);
}
else {
/* interpret the result as a double measured in seconds.
As the profiler works with long long internally
As the profiler works with _PyTime_t internally
we convert it to a large integer */
double val = PyFloat_AsDouble(o);
/* error handling delayed to the code below */
result = (long long) (val * DOUBLE_TIMER_PRECISION);
err = _PyTime_FromSecondsObject(&result, o, _PyTime_ROUND_FLOOR);
}
Py_DECREF(o);
if (PyErr_Occurred()) {
if (err < 0) {
PyErr_WriteUnraisable(pObj->externalTimer);
return 0;
}
return result;
}
#define CALL_TIMER(pObj) ((pObj)->externalTimer ? \
CallExternalTimer(pObj) : \
hpTimer())
static inline _PyTime_t
call_timer(ProfilerObject *pObj)
{
if (pObj->externalTimer != NULL) {
return CallExternalTimer(pObj);
}
else {
return _PyTime_GetPerfCounter();
}
}
/*** ProfilerObject ***/
@ -332,14 +281,14 @@ initContext(ProfilerObject *pObj, ProfilerContext *self, ProfilerEntry *entry)
if (subentry)
++subentry->recursionLevel;
}
self->t0 = CALL_TIMER(pObj);
self->t0 = call_timer(pObj);
}
static void
Stop(ProfilerObject *pObj, ProfilerContext *self, ProfilerEntry *entry)
{
long long tt = CALL_TIMER(pObj) - self->t0;
long long it = tt - self->subt;
_PyTime_t tt = call_timer(pObj) - self->t0;
_PyTime_t it = tt - self->subt;
if (self->previous)
self->previous->subt += tt;
pObj->currentProfilerContext = self->previous;
@ -631,12 +580,14 @@ profiler_getstats(ProfilerObject *pObj, PyObject* noarg)
statscollector_t collect;
if (pending_exception(pObj))
return NULL;
if (!pObj->externalTimer)
collect.factor = hpTimerUnit();
else if (pObj->externalTimerUnit > 0.0)
if (!pObj->externalTimer || pObj->externalTimerUnit == 0.0) {
_PyTime_t onesec = _PyTime_FromSeconds(1);
collect.factor = (double)1 / onesec;
}
else {
collect.factor = pObj->externalTimerUnit;
else
collect.factor = 1.0 / DOUBLE_TIMER_PRECISION;
}
collect.list = PyList_New(0);
if (collect.list == NULL)
return NULL;
@ -882,7 +833,6 @@ PyInit__lsprof(void)
(PyObject*) &StatsEntryType);
PyModule_AddObject(module, "profiler_subentry",
(PyObject*) &StatsSubEntryType);
empty_tuple = PyTuple_New(0);
initialized = 1;
return module;
}