Pytest: Get the best available time counter for node call duration calculation

[smarie]

Hi all

In pytest-harvest I provide a function to easily retrieve all information available about test nodes. Among these information, a "duration" is provided (the original from pytest is in seconds, I convert it to ms). However it seems that this number is calculated (in CallInfo) using time(), which is not the most precise tool we have to measure durations in python.

Other built-in possibilities are suggested here.

A good source of inspiration can also be found in pytest-benchmark.

Let me know if it makes sense

[RonnyPfannschmidt]

sounds like we could switch to perf_counter mid 2019 after we branch of the 2.7 bugfixing branch

[smarie]

That's a fast and positive answer, awesome !

[Zac-HD]

We actually can't change without breaking existing code, because the reference point for perf_counter is undefined but the .start and .stop attributes are public API.

However, I would strongly support adding an .duration attribute of type datetime.timedelta, calculated from perf_counter on Python 3 (and falling back to time on Python 2).

[smarie]

You are right. This duration attribute would then need to be used in the report object in place of this (stop - start) statement

Also we should maybe check that in python 2.7 there are no better alternatives. For example datetime.now() is maybe more accurate than time() ? (I did not check)

[RonnyPfannschmidt]

as far as im concerned - any monotonic higher resolution time source will do us better than time.time()

start/end are both floats and we never defined a point of reference, so its perfectly reasonable to me, to just switch out the data source there without too much of a hassle

[smarie]

Hi there, any other feedback on this topic ? I can try a PR one of these weeks if needed.

[nicoddemus]

Also we should maybe check that in python 2.7 there are no better alternatives. For example datetime.now()

Not sure about datetime.now(), but on Windows for example time.clock() is more precise... but I agree we can probably wait until we drop 2.7 (which should be soon anyway).

[RonnyPfannschmidt]

Anything not a float is a breaking api change

[nicoddemus]

Anything not a float is a breaking api change

Agreed, I was mentioning datetime.now() just regarding its precision

[Zac-HD]

Better idea: on Python 3, we could track the duration using perf_counter(), get the stop time with time(), and then adjust the start attribute to match. Backwards compatible, and resolution limited not by the clock but by float64 (to slightly sub-microsecond precision)!

I'd be happy to accept a PR for this now, or it could wait for pytest 5.0 at which point it wouldn't need a fallback path for Python 2.

[nicoddemus]

Better idea: on Python 3, we could track the duration using perf_counter(), get the stop time with time(), and then adjust the start attribute to match. Backwards compatible, and resolution limited not by the clock but by float64 (to slightly sub-microsecond precision)!

I think we can just go ahead and use perf_counter to obtain duration, without resorting to time.time() at all; we never made any promises about the precision of the duration attribute, only about the data type being float.

[Zac-HD]

I meant that instead of adding a duration attribute, we could use time() to get the stop time, and calculate the start time from perf_counter() instead. No API change, so no or changed attributes, just higher precision.

[nicoddemus]

We don't have start/end attributes, only a duration attribute: https://github.com/pytest-dev/pytest/blob/master/src/_pytest/reports.py#L332

Now I understand, thanks, I got confused because I thought we were talking about the duration of the TestReport object, not CallInfo, my bad. 😅

[smarie]

I finally took some time to fix this, see #6939.