Skip to content

Commit

Permalink
src/sage/doctest/util.py: cputime for pexpect interfaces on Linux/BSD
Browse files Browse the repository at this point in the history
After switching the doctests to report cputime instead of walltime,
the running-time measurements for tests using pexpect interfaces are
off because the time spent in subprocesses is not accounted
for. Fixing this turns out not to be easy: the cputime() function in
sage.misc.timing can try to account for them, but it is essentially
asking the subprocess to compute its own cputime. This has faults:

  1. Not every pexpect interface implemented (or can implement)
     such a method.

  2. The pexpect interface needs to be in good working condition
     before we can ask the subprocess to do anything. That's often
     not the case at the end of a "sage: ..." line in a doctest.
     Particularly it's not true in all of the tests for low-level
     details of our pexpect interface itself.

Instead, this commit parses /proc/<pid>/stat to obtain the cputime
numbers for pexpext processes. This works well with one caveat: that
information is only available on Linux and BSD.

Having a solution that only works on some platforms is not actually
too problematic. The motivation for measuring these times in the
doctest framework is that someone should notice an outrageously long
test and fix or report it. So, it's enough that the measurements be
accurate on only some platforms -- particularly where the CI is
run. Furthermore, the information is only both missing and potentially
useful for long-running pexpect tests, which are relatively rare.

It would be possible to implement the same thing for macOS using its
own platform-specific interface if anyone is motivated to do so. It
would also make sense to use psutil to obtain this information once
we have upgraded to a version of ipykernel that reintroduces it as
a dependency (see sagemathGH-33772).

Issue: sagemathGH-32981
  • Loading branch information
orlitzky committed Sep 9, 2023
1 parent d123fab commit 840b7dd
Showing 1 changed file with 66 additions and 4 deletions.
70 changes: 66 additions & 4 deletions src/sage/doctest/util.py
Original file line number Diff line number Diff line change
Expand Up @@ -22,8 +22,8 @@
# https://www.gnu.org/licenses/
# ****************************************************************************

from sage.misc.timing import walltime, cputime

from sage.misc.timing import walltime
from os import sysconf, times

def count_noun(number, noun, plural=None, pad_number=False, pad_noun=False):
"""
Expand Down Expand Up @@ -103,6 +103,68 @@ class Timer:
{}
sage: TestSuite(Timer()).run()
"""

def _pid_cpu_seconds(self, pid):
r"""
Parse the ``/proc`` filesystem to get the cputime of the given
``pid``.
This also includes the times for child processes **that have
been ``wait()``ed for and terminated**. Specifically, pexpect
processes DO NOT fall into that category.
"""
with open(f"/proc/{pid}/stat", "r") as statfile:
stats = statfile.read().split()

# man 5 proc (linux)
cputicks = sum( float(s) for s in stats[13:17] )

hertz = sysconf("SC_CLK_TCK")
return (cputicks / hertz)

def _quick_cputime(self):
r"""
A fast and replacement for ``sage.misc.misc.cputime``.
This is a "reliable" replacement (on Linux/BSD) that takes
subprocesses (particularly pexpect interfaces) into
account. The ``cputime()`` function from the ``misc`` module
can be passed ``subprocesses=True``, but this has a few
faults; mainly that it relies on each pexpect interface to
implement its own ``cputime()`` function. And most of our
pexpect interfaces either don't implement one, or implement
one in a way that requires the subprocess (being pexpected) to
be in perfect working condition -- that will often not be the
case at the end of a doctest line.
OUTPUT:
A float measuring the cputime in seconds of the sage process
and all its subprocesses.
"""
# Start by using os.times() to get the cputime for sage itself
# and any subprocesses that have been wait()ed for and that
# have terminated.
cputime = sum( times()[:4] )

# Now try to get the times for any pexpect interfaces, since
# they do not fall into the category above.
from sage.interfaces.quit import expect_objects
for s in expect_objects:
S = s()
if S and S.is_running():
try:
cputime += self._pid_cpu_seconds(S.pid())
except (ArithmeticError, LookupError, OSError,
TypeError, ValueError):
# This will fail anywhere but linux/BSD, but
# there's no good cross-platform way to get the
# cputimes from pexpect interfaces without
# totally mucking up the doctests.
pass

return cputime

def start(self):
"""
Start the timer.
Expand All @@ -115,7 +177,7 @@ def start(self):
sage: Timer().start()
{'cputime': ..., 'walltime': ...}
"""
self.cputime = cputime()
self.cputime = self._quick_cputime()
self.walltime = walltime()
return self

Expand All @@ -133,7 +195,7 @@ def stop(self):
sage: timer.stop()
{'cputime': ..., 'walltime': ...}
"""
self.cputime = cputime(self.cputime)
self.cputime = self._quick_cputime() - self.cputime
self.walltime = walltime(self.walltime)
return self

Expand Down

0 comments on commit 840b7dd

Please sign in to comment.