Trac #33443: slow doctest improvements (isogeny_small_degree, functio…

…n_field, doctest/test.py)

In this ticket we add some improvements for slow doctests in files that
used to take more than 200s for --long. Also mark some tests as long so
the file runs fast in not long mode.

 - isogeny_small_degree: the worst part is already fixed by 33293.
 - function_field: save 100s by tuning down number of repetitions.
 - doctests/test: this one spawns `sage-runtests` a lot of times to
test, by tuning the cmdline this takes 1s less for each without
compromising the test. Also improve the time it takes to test
`die_timeout` by making it adjustable on the cmdline.

URL: https://trac.sagemath.org/33443
Reported by: tornaria
Ticket author(s): Gonzalo Tornaría
Reviewer(s): Michael Orlitzky

src/bin/sage-runtests

@@ -111,6 +111,8 @@ if __name__ == "__main__":
     # The --serial option is only really for internal use, better not
     # document it.
     parser.add_argument("--serial", action="store_true", default=False, help=argparse.SUPPRESS)
+    # Same for --die_timeout
+    parser.add_argument("--die_timeout", type=int, default=-1, help=argparse.SUPPRESS)
 
     parser.add_argument("filenames", help="file names", nargs='*')
 

src/sage/categories/sets_cat.py

@@ -1277,7 +1277,7 @@ def _test_elements_eq_transitive(self, **options):
             """
             tester = self._tester(**options)
             S = list(tester.some_elements())
-            n = tester._max_runs
+            n = max(tester._max_runs, 8)
             if (len(S)+2)**3 <= n:
                 S = list(S) + [None, 0]
             else:

src/sage/doctest/control.py

@@ -100,6 +100,7 @@ def __init__(self, **kwds):
         self.nthreads = 1
         self.serial = False
         self.timeout = -1
+        self.die_timeout = -1
         self.all = False
         self.installed = False
         self.logfile = None

src/sage/doctest/forker.py

@@ -1751,6 +1751,9 @@ def parallel_dispatch(self):
             die_timeout = 600
         elif die_timeout < 60:
             die_timeout = 60
+        # allow override via cmdline option
+        if opt.die_timeout >= 0:
+            die_timeout = opt.die_timeout
 
         # If we think that we can not finish running all tests until
         # target_endtime, we skip individual tests. (Only enabled with

src/sage/doctest/test.py

@@ -23,7 +23,8 @@
 
 Check that :trac:`2235` has been fixed::
 
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=0", "longtime.rst"], **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",    # long time
+    ....:       "--random-seed=0", "--optional=sage", "longtime.rst"], **kwds)
     Running doctests...
     Doctesting 1 file.
     sage -t --warn-long 0.0 --random-seed=0 longtime.rst
@@ -33,7 +34,8 @@
     ----------------------------------------------------------------------
     ...
     0
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=0", "-l", "longtime.rst"], **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",    # long time
+    ....:      "--random-seed=0", "--optional=sage", "-l", "longtime.rst"], **kwds)
     Running doctests...
     Doctesting 1 file.
     sage -t --long --warn-long 0.0 --random-seed=0 longtime.rst
@@ -46,7 +48,8 @@
 
 Check handling of tolerances::
 
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=0", "tolerance.rst"], **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",    # long time
+    ....:      "--random-seed=0", "--optional=sage", "tolerance.rst"], **kwds)
     Running doctests...
     Doctesting 1 file.
     sage -t --warn-long 0.0 --random-seed=0 tolerance.rst
@@ -115,7 +118,8 @@
 
 Test the ``--initial`` option::
 
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=0", "-i", "initial.rst"], **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",    # long time
+    ....:      "--random-seed=0", "--optional=sage", "-i", "initial.rst"], **kwds)
     Running doctests...
     Doctesting 1 file.
     sage -t --warn-long 0.0 --random-seed=0 initial.rst
@@ -145,7 +149,8 @@
 
 Test the ``--exitfirst`` option::
 
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=0", "--exitfirst", "initial.rst"], **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",    # long time
+    ....:      "--random-seed=0", "--optional=sage", "--exitfirst", "initial.rst"], **kwds)
     Running doctests...
     Doctesting 1 file.
     sage -t --warn-long 0.0 --random-seed=0 initial.rst
@@ -171,8 +176,9 @@
 
     sage: from copy import deepcopy
     sage: kwds2 = deepcopy(kwds)
-    sage: kwds2['env'].update({'SAGE_TIMEOUT': '3', 'CYSIGNALS_CRASH_NDEBUG': '1'})
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=0", "99seconds.rst"], **kwds2)  # long time
+    sage: kwds2['env'].update({'SAGE_TIMEOUT': '1', 'CYSIGNALS_CRASH_NDEBUG': '1'})
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",    # long time
+    ....:      "--random-seed=0", "--optional=sage", "99seconds.rst"], **kwds2)
     Running doctests...
     Doctesting 1 file.
     sage -t --warn-long 0.0 --random-seed=0 99seconds.rst
@@ -188,7 +194,8 @@
 
 Test handling of ``KeyboardInterrupt`` in doctests::
 
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=0", "keyboardinterrupt.rst"], **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",    # long time
+    ....:      "--random-seed=0", "--optional=sage", "keyboardinterrupt.rst"], **kwds)
     Running doctests...
     Doctesting 1 file.
     sage -t --warn-long 0.0 --random-seed=0 keyboardinterrupt.rst
@@ -210,7 +217,8 @@
 
 Interrupt the doctester::
 
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=0", "interrupt.rst"], **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",    # long time
+    ....:      "--random-seed=0", "--optional=sage", "interrupt.rst"], **kwds)
     Running doctests...
     Doctesting 1 file.
     Killing test interrupt.rst
@@ -229,6 +237,7 @@
     sage: kwds2 = deepcopy(kwds)
     sage: kwds2['env']['DOCTEST_TEST_PID_FILE'] = F  # Doctester will write its PID in this file
     sage: subprocess.call(["sage", "-tp", "1000000", "--timeout=120",  # long time
+    ....:      "--die_timeout=10", "--optional=sage",
     ....:      "--warn-long", "0", "99seconds.rst", "interrupt_diehard.rst"], **kwds2)
     Running doctests...
     Doctesting 2 files using 1000000 threads...
@@ -242,20 +251,21 @@
 
 Even though the doctester master process has exited, the child process
 is still alive, but it should be killed automatically
-in max(60, 120 * 0.05) = 60 seconds::
+after the `die_timeout` given above (10 seconds)::
 
     sage: pid = int(open(F).read())    # long time
     sage: time.sleep(2)                # long time
     sage: os.kill(pid, signal.SIGQUIT) # long time; 2 seconds passed => still alive
-    sage: time.sleep(63)               # long time
-    sage: os.kill(pid, signal.SIGQUIT) # long time; 65 seconds passed => dead
+    sage: time.sleep(8)                # long time
+    sage: os.kill(pid, signal.SIGQUIT) # long time; 10 seconds passed => dead
     Traceback (most recent call last):
     ...
     ProcessLookupError: ...
 
 Test a doctest failing with ``abort()``::
 
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=0", "abort.rst"], **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",    # long time
+    ....:      "--random-seed=0", "--optional=sage", "abort.rst"], **kwds)
     Running doctests...
     Doctesting 1 file.
     sage -t --warn-long 0.0 --random-seed=0 abort.rst
@@ -278,7 +288,8 @@
 
 A different kind of crash::
 
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=0", "fail_and_die.rst"], **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",    # long time
+    ....:      "--random-seed=0", "--optional=sage", "fail_and_die.rst"], **kwds)
     Running doctests...
     Doctesting 1 file.
     sage -t --warn-long 0.0 --random-seed=0 fail_and_die.rst
@@ -302,7 +313,8 @@
 
 Test that ``sig_on_count`` is checked correctly::
 
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=0", "sig_on.rst"], **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",    # long time
+    ....:      "--random-seed=0", "--optional=sage", "sig_on.rst"], **kwds)
     Running doctests...
     Doctesting 1 file.
     sage -t --warn-long 0.0 --random-seed=0 sig_on.rst
@@ -327,7 +339,9 @@
 Test logfiles in serial and parallel mode (see :trac:`19271`)::
 
     sage: t = tmp_filename()
-    sage: subprocess.call(["sage", "-t", "--serial", "--warn-long", "0", "--random-seed=0", "--logfile", t, "simple_failure.rst"], stdout=open(os.devnull, "w"), **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--serial", "--warn-long", "0",    # long time
+    ....:      "--random-seed=0", "--optional=sage", "--logfile", t, "simple_failure.rst"],
+    ....:      stdout=open(os.devnull, "w"), **kwds)
     1
     sage: print(open(t).read())  # long time
     Running doctests...
@@ -350,7 +364,9 @@
     ----------------------------------------------------------------------
     ...
 
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=0", "--logfile", t, "simple_failure.rst"], stdout=open(os.devnull, "w"), **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",    # long time
+    ....:      "--random-seed=0", "--optional=sage", "--logfile", t, "simple_failure.rst"],
+    ....:      stdout=open(os.devnull, "w"), **kwds)
     1
     sage: print(open(t).read())  # long time
     Running doctests...
@@ -375,7 +391,9 @@
 
 Test the ``--debug`` option::
 
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=0", "--debug", "simple_failure.rst"], stdin=open(os.devnull), **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",    # long time
+    ....:      "--random-seed=0", "--optional=sage", "--debug", "simple_failure.rst"],
+    ....:      stdin=open(os.devnull), **kwds)
     Running doctests...
     Doctesting 1 file.
     sage -t --warn-long 0.0 --random-seed=0 simple_failure.rst
@@ -408,7 +426,9 @@
 
 Test running under gdb, without and with a timeout::
 
-    sage: subprocess.call(["sage", "-t",  "--warn-long", "0", "--random-seed=0", "--gdb", "1second.rst"], stdin=open(os.devnull), **kwds)  # long time, optional: gdb
+    sage: subprocess.call(["sage", "-t",  "--warn-long", "0",   # long time, optional: gdb
+    ....:      "--random-seed=0", "--optional=sage", "--gdb", "1second.rst"],
+    ....:      stdin=open(os.devnull), **kwds)
     exec gdb ...
     Running doctests...
     Doctesting 1 file...
@@ -422,15 +442,18 @@
 
 gdb might need a long time to start up, so we allow 30 seconds::
 
-    sage: subprocess.call(["sage", "-t", "--gdb",  "--warn-long", "0", "--random-seed=0", "-T30", "99seconds.rst"], stdin=open(os.devnull), **kwds)  # long time, optional: gdb
+    sage: subprocess.call(["sage", "-t",  "--warn-long", "0",   # long time, optional: gdb
+    ....:      "--random-seed=0", "--optional=sage", "--gdb", "-T30", "99seconds.rst"],
+    ....:      stdin=open(os.devnull), **kwds)
     exec gdb ...
     Running doctests...
         Timed out
     4
 
 Test the ``--show-skipped`` option::
 
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=0", "--show-skipped", "show_skipped.rst"], **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",    # long time
+    ....:      "--random-seed=0", "--optional=sage", "--show-skipped", "show_skipped.rst"], **kwds)
     Running doctests ...
     Doctesting 1 file.
     sage -t --warn-long 0.0 --random-seed=0 show_skipped.rst
@@ -449,7 +472,8 @@
 
 Optional tests are run correctly::
 
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--long", "--random-seed=0", "--show-skipped", "--optional=sage,gap", "show_skipped.rst"], **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--long",  # long time
+    ....:      "--random-seed=0", "--show-skipped", "--optional=sage,gap", "show_skipped.rst"], **kwds)
     Running doctests ...
     Doctesting 1 file.
     sage -t --long --warn-long 0.0 --random-seed=0 show_skipped.rst
@@ -464,7 +488,8 @@
     ...
     0
 
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--long", "--random-seed=0", "--show-skipped", "--optional=gAp", "show_skipped.rst"], **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--long",  # long time
+    ....:      "--random-seed=0", "--show-skipped", "--optional=gAp", "show_skipped.rst"], **kwds)
     Running doctests ...
     Doctesting 1 file.
     sage -t --long --warn-long 0.0 --random-seed=0 show_skipped.rst
@@ -482,7 +507,8 @@
 
 Test an invalid value for ``--optional``::
 
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=0", "--optional=bad-option", "show_skipped.rst"], **kwds)
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",
+    ....:      "--random-seed=0", "--optional=bad-option", "show_skipped.rst"], **kwds)
     Traceback (most recent call last):
     ...
     ValueError: invalid optional tag 'bad-option'
@@ -496,7 +522,8 @@
     sage: from copy import deepcopy
     sage: kwds2 = deepcopy(kwds)
     sage: kwds2['env']['DOCTEST_DELETE_FILE'] = F
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=0", "atexit.rst"], **kwds2)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",    # long time
+    ....:      "--random-seed=0", "--optional=sage", "atexit.rst"], **kwds2)
     Running doctests...
     Doctesting 1 file.
     sage -t --warn-long 0.0 --random-seed=0 atexit.rst
@@ -515,7 +542,8 @@
 
 Test that random tests are reproducible::
 
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=0", "random_seed.rst"], **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",    # long time
+    ....:      "--random-seed=0", "--optional=sage", "random_seed.rst"], **kwds)
     Running doctests...
     Doctesting 1 file.
     sage -t --warn-long 0.0 --random-seed=0 random_seed.rst
@@ -536,7 +564,8 @@
     ----------------------------------------------------------------------
     ...
     1
-    sage: subprocess.call(["sage", "-t", "--warn-long", "0", "--random-seed=1", "random_seed.rst"], **kwds)  # long time
+    sage: subprocess.call(["sage", "-t", "--warn-long", "0",    # long time
+    ....:      "--random-seed=1", "--optional=sage", "random_seed.rst"], **kwds)
     Running doctests...
     Doctesting 1 file.
     sage -t --warn-long 0.0 --random-seed=1 random_seed.rst

src/sage/rings/function_field/function_field.py

@@ -111,22 +111,21 @@
     sage: m = L.completion(pl, prec=5)
     sage: m(x)
     I + s + O(s^5)
-    sage: m(y)
+    sage: m(y)                             # long time (4s)
     -2*s + (-4 - I)*s^2 + (-15 - 4*I)*s^3 + (-75 - 23*I)*s^4 + (-413 - 154*I)*s^5 + O(s^6)
-    sage: m(y)^2 + m(y) + m(x) + 1/m(x)
+    sage: m(y)^2 + m(y) + m(x) + 1/m(x)    # long time (8s)
     O(s^5)
 
 TESTS::
 
     sage: TestSuite(J).run()
-    sage: TestSuite(K).run(max_runs=1024) # long time (5s)
-    sage: TestSuite(L).run(max_runs=64)   # long time (10s)
-    sage: TestSuite(M).run(max_runs=32)   # long time (30s)
-    sage: TestSuite(N).run(max_runs=64, skip = '_test_derivation')  # long time (8s)
-    sage: TestSuite(O).run(max_runs=128, skip = '_test_derivation') # long time (8s)
-
+    sage: TestSuite(K).run(max_runs=256)   # long time (10s)
+    sage: TestSuite(L).run(max_runs=8)     # long time (25s)
+    sage: TestSuite(M).run(max_runs=8)     # long time (35s)
+    sage: TestSuite(N).run(max_runs=8, skip = '_test_derivation')    # long time (15s)
+    sage: TestSuite(O).run()
     sage: TestSuite(R).run()
-    sage: TestSuite(S).run() # long time (3s)
+    sage: TestSuite(S).run()               # long time (4s)
 
 Global function fields
 ----------------------
@@ -288,7 +287,7 @@ def __init__(self, base_field, names, category=FunctionFields()):
         TESTS::
 
             sage: K.<x> = FunctionField(QQ)
-            sage: TestSuite(K).run()
+            sage: TestSuite(K).run()               # long time (3s)
         """
         Field.__init__(self, base_field, names=names, category=category)
 
@@ -730,7 +729,7 @@ def _test_derivation(self, **options):
         EXAMPLES::
 
             sage: K.<x> = FunctionField(QQ)
-            sage: TestSuite(K).run() # indirect doctest
+            sage: TestSuite(K).run()    # indirect doctest, long time (3s)
         """
         tester = self._tester(**options)
         S = tester.some_elements()
@@ -1231,7 +1230,7 @@ def __init__(self, polynomial, names, category=None):
             sage: K.<x> = FunctionField(QQ); R.<y> = K[]
             sage: L = K.extension(y^5 - x^3 - 3*x + x*y); L
             Function field in y defined by y^5 + x*y - x^3 - 3*x
-            sage: TestSuite(L).run()  # long time
+            sage: TestSuite(L).run(max_runs=512)   # long time (15s)
 
         We can set the variable name, which doesn't have to be y::
 
@@ -2836,7 +2835,8 @@ def places_above(self, p):
             sage: F.<y> = K.extension(Y^3 - x^2*(x^2 + x + 1)^2)
             sage: O = K.maximal_order()
             sage: pls = [O.ideal(x-QQbar(sqrt(c))).place() for c in [-2, -1, 0, 1, 2]]
-            sage: all(q.place_below() == p for p in pls for q in F.places_above(p))
+            sage: all(q.place_below() == p         # long time (4s)
+            ....:     for p in pls for q in F.places_above(p))
             True
         """
         R = self.base_field()
@@ -3039,7 +3039,7 @@ class FunctionField_global(FunctionField_simple):
 
         sage: K.<x> = FunctionField(GF(4)); _.<Y> = K[]
         sage: L.<y> = K.extension((1 - x)*Y^7 - x^3)
-        sage: L.gaps()
+        sage: L.gaps()                         # long time (6s)
         [1, 2, 3]
 
     or may define a trivial extension::
@@ -3059,7 +3059,7 @@ def __init__(self, polynomial, names):
 
             sage: K.<x> = FunctionField(GF(5)); _.<Y> = K[]
             sage: L.<y> = K.extension(Y^3 - (x^3 - 1)/(x^3 - 2))
-            sage: TestSuite(L).run()
+            sage: TestSuite(L).run()               # long time (7s)
         """
         FunctionField_polymod.__init__(self, polynomial, names)
 
@@ -3754,7 +3754,7 @@ def __init__(self, constant_field, names, category=None):
 
             sage: K.<t> = FunctionField(CC); K
             Rational function field in t over Complex Field with 53 bits of precision
-            sage: TestSuite(K).run()
+            sage: TestSuite(K).run()               # long time (5s)
 
             sage: FunctionField(QQ[I], 'alpha')
             Rational function field in alpha over Number Field in I with defining polynomial x^2 + 1 with I = 1*I