Update doctesting framework

[robertwb]

There are several improvements that would be good to make, including but not limited to:

1. Forking rather than starting up a new Sage each time.
2. Customizable comparison rather than mutating doctests into new doctests (e.g. followup to #10952).
3. Eliminate need to write temporary files for every doctested file.
4. Constant headaches caused by the difference in doctesting library vs. non-library files.
5. The ability to drop into a debugger if a doctest raises an exception.

Robert's code is at

​http://code.google.com/p/sagemath-timer/

Apply 12415_framework.patch​, 12415_doctest_fixes.patch​, 12415_doc.patch​, 12415_review.patch​, 12415_test.patch​, 12415_review_review.patch​, 12415_review3.patch​, 12415_manifest.patch​, 12415_rebase_58.patch​

Apply 12415_script.patch​ and 12415_script_review.patch​ to the scripts repo

Apply 12415_spkg_bin_sage.patch​ to the root repo

Follow-up or other doctest-related tickets: #12720, #12722, #13610, #13063, #14152, #14153, #14203, #12281.

[roed]

I'm working on this. E-mail me if you want to collaborate.

[robertwb]

12415_2.patch seems to contain a lot of tempfile changes, could you split out the doctest changes into a separate patch (or are these affecting doctests?)

[ohanar]

apparently even I forget my trac username is not what it should be

[roed]

I've moved the patches dealing with temporary files to #13147.

[roed]

Ready for review!

There are still a few known issues:

• valgrinding under sage -t doesn't work. I haven't used valgrind much and don't know how to resolve this.
• The fix at #13147 probably needs work: I'm getting a failure in sage.rings.polynomial.multi_polynomial_libsingular to do with garbage collection. I'm working on it.
• I'm in the process of updating the developer guide.

But I wanted to get some other people involved in reviewing.

[jhpalmieri]

This may be a silly question, but how do I use the new framework? Don't we need changes to the scripts repo, too? (If I just run sage -t FILES, I don't see the various messages, like Doctesting ..., that should be printed by run_doctests are not printed, so sage -t is not yet using the new framework.)

One of the patches also didn't apply cleanly to 5.1.beta5:

hg qimport -P ~/Downloads/12415_stderr.patch 
adding 12415_stderr.patch to series file
applying 12415_stderr.patch
patching file sage/lfunctions/lcalc.py
Hunk #1 FAILED at 226
1 out of 2 hunks FAILED -- saving rejects to file sage/lfunctions/lcalc.py.rej
patch failed, unable to continue (try -v)
patch failed, rejects left in working dir
errors during apply, please fix and refresh 12415_stderr.patch

[roed]

Did you apply the new dependencies (#13145, #13146, #13147)? There are some more patches to other repositories: I'll update the ticket description.

[roed]

The description is updated: let me know if you have any more problems. I think you need to apply 12415_stderr_vs_51b5.patch instead of 12415_stderr.patch.

[jhpalmieri]

Regarding 12415_spkg_bin_sage.patch​, the file in question should be part of the root repo.

[jhpalmieri]

One regression: with the old set-up, running sage -tp FILES (with no argument for tp) would choose the number of threads automatically. With the new set-up, this command gives an error, because FILES is not an integer. Therefore I think that, for example, make ptestlong will fail. (The file sage-runtests says that the default value for nthreads is 1, but I don't think optparse is dealing with the missing argument properly here. Also, passing the argument 0 causes doctests to never happen: maybe it's using 0 threads instead of minimum(8, cpu_count()).

[jhpalmieri]

I would suggest the following two changes: for the scripts repo:

sage-runtests

@@ -5 +5 @@
 if __name__ == "__main__":
     parser = optparse.OptionParser()
 
-    parser.add_option("-p", "--nthreads", type=int, default=1, metavar="N", help="tests in parallel using N threads with 0 interpreted as minimum(8, cpu_count())")
+    parser.add_option("-p", "--nthreads", type="string", default=1, metavar="N", help="tests in parallel using N threads with 0 interpreted as minimum(8, cpu_count())")
     parser.add_option("--serial", action="store_true", default=False, help="run tests in a single process in series")
     parser.add_option("--timeout", type=int, default=-1, help="timeout (in seconds) for doctesting one file")
     parser.add_option("-a", "--all", action="store_true", default=False, help="test all files in the Sage library")
@@ -49 +49 @@
     parser.add_option("--stats_path", "--stats-path", default=os.path.join(os.path.expanduser("~/.sage/timings2.json")), \
                           help="path to a json dictionary for the latest run storing a timing for each file")
 
+    options, args = parser.parse_args()
+    try:
+        options.nthreads = int(options.nthreads)
+    except ValueError:
+        args.insert(0, options.nthreads.strip())
+        options.nthreads = 0
+
+    if options.nthreads == 0:
+        try:
+            options.nthreads = int(os.environ['SAGE_NUM_THREADS_PARALLEL'])
+        except KeyError:
+            options.nthreads = 1
+
     from sage.doctest.control import DocTestController
-    DC = DocTestController(*parser.parse_args())
+    DC = DocTestController(options, args)
     err = DC.run()
     sys.exit(err)

and for the Sage library:

sage/doctest/control.py

@@ -433 +433 @@
             else:
                 nother += 1
         if nfiles + ndbsources + nother:
-            self.log("Doctesting %s."%(", ".join((["%s file%s"%(nfiles, "s" if nfiles > 1 else "")] if nfiles else []) +
-                                                 (["%s other sources"%nother] if nother else []))))
+            self.log("Doctesting %s"%(", ".join((["%s file%s"%(nfiles, "s" if nfiles > 1 else "")] if nfiles else []) +
+                                                 (["%s other sources"%nother] if nother else [])))
+                + " using %s threads."%self.options.nthreads if self.options.nthreads > 1 else ".")
             self.reporter = DocTestReporter(self)
             self.dispatcher = DocTestDispatcher(self)
             try:

Or something like that. I guess you should also print the number of threads when you print "Doctesting entire Sage library.", etc.

[roed]

I've updated the option parsing to allow -p to take no options (though I used a callback so that the -p doesn't have to be last). I changed 12415_spkg_bin_sage.patch to be an actual patch against the root repository. I also made a small change to the debug functionality (printing the doctest that failed before dropping into the debugger).

Since I'm modifying four repositories, I'll just update the patches rather than creating lots of referee patches (unless the referee objects!).

[jdemeyer]

sage/parallel/decorate.py: Use

Unhandled SIG...

(on systems, this would give a SIGBUS: Bus Error instead)

[jdemeyer]

Please explain why you're adding nodoctest to some of the files in doc/?

[jdemeyer]

Are all the options in sage-runtests actually implemented? (it seems some of them are meant for #12720, these should not be added here)

[jdemeyer]

I guess you're no longer using the scripts sage-test, sage-ptest, sage-doctest, sage-maketest, perhaps sage-test-new and sage-test-import. Remove these.

[jdemeyer]

Why does the doctesting framework need to be imported from sage.all?

[ohanar]

Replying to jdemeyer:

Why does the doctesting framework need to be imported from sage.all?

I don't think it needs to be, but it makes it easy to test (and debug) doctests from within Sage:

sage: run_doctests(sage.rings.integer)
...

[jdemeyer]

You have two instances of

except:

in the new code.

The one for os.kill() should just catch OSError, for the other one replace

except KeyboardInterrupt:
    pass
except:

by

except Exception:

[jdemeyer]

Replace

import multiprocessing 
options.nthreads = os.getenv('SAGE_NUM_THREADS_PARALLEL',min(8, multiprocessing.cpu_count()))

by

options.nthreads = int(os.getenv('SAGE_NUM_THREADS_PARALLEL', 1))

(don't reinvent the sage-num-threads.py wheel)

[jdemeyer]

Planning to make a reviewer patch, so hang on...

[jdemeyer]

This actually fails on the very first thing I tried (after applying all patches and doing sage -b):

jdemeyer@sage:/release/sage-5.1.beta5-doctest$ ./sage -t devel/sage/sage/rings/padics/
argv ['/release/sage-5.1.beta5-doctest/local/bin/sage-runtests', 'devel/sage/sage/rings/padics/']
Traceback (most recent call last):
  File "/release/sage-5.1.beta5-doctest/local/bin/sage-runtests", line 68, in <module>
    DC = DocTestController(*parser.parse_args())
  File "/release/sage-5.1.beta5-doctest/local/lib/python2.7/site-packages/sage/doctest/control.py", line 116, in __init__
    if options.nthreads == 0:
AttributeError: Values instance has no attribute 'nthreads'

Am I doing something wrong?

[jdemeyer]

Building from scratch and doing make ptest gives:

argv ['/release/merger/sage-5.1.beta5-12415/local/bin/sage-runtests', '-p', '--sagenb', 'devel/sage/doc/common', 'devel/sage/doc/de', 'devel/sage/doc/en', 'devel/sage/doc/fr', 'devel/sage/doc/ru', 'devel/sage/doc/tr', 'devel/sage/sage']
next_arg: --sagenb
Running doctests with ID 2012-06-25-12-57-22-d71deecd.
Doctesting the Sage notebook.
Doctesting 2067 files using 6 threads
Usage: sage -docbuild [OPTIONS] DOCUMENT (FORMAT | COMMAND)

sage-runtests: error: no such option: -p
**********************************************************************
File "programming", line 620, in programming
Failed example:
    for i in range(5):
Exception raised:
    Traceback (most recent call last):
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 572, in _run
        compileflags, 1)
      File "<doctest programming[0]>", line 1
        for i in range(5):
                         ^
    SyntaxError: unexpected EOF while parsing
**********************************************************************
1 items had failures:
   1 of 113 in programming
***Test Failed*** 1 failures.
**********************************************************************
File "programming", line 578, in programming
Failed example:
    for i in range(5):
Exception raised:
    Traceback (most recent call last):
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 572, in _run
        compileflags, 1)
      File "<doctest programming[0]>", line 1
        for i in range(5):
                         ^
    SyntaxError: unexpected EOF while parsing
**********************************************************************
1 items had failures:
   1 of 113 in programming
***Test Failed*** 1 failures.
**********************************************************************
File "sage.misc.sh", line 20, in sage.misc.sh.Sh.eval
Failed example:
    sh.eval('''echo "Hello there"\nif [ $? -eq 0 ]; then\necho "good"\nfi''')
Expected:
    /...
    ''
Got:
    Hello there
    good
    /release/merger/sage-5.1.beta5-12415
    ''
**********************************************************************
File "interfaces", line 331, in interfaces
Failed example:
    maxima.plot3d("[cos(x)*(3 + y*cos(x/2)), sin(x)*(3 + y*cos(x/2)),\
      y*sin(x/2)]", "[x, -4, 4]", "[y, -4, 4]",\ 
      '[plot_format, openmath]') # not tested
Exception raised:
    Traceback (most recent call last):
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 572, in _run
        compileflags, 1)
      File "<doctest interfaces[0]>", line 2
        maxima.plot3d("[cos(x)*(3 + y*cos(x/2)), sin(x)*(3 + y*cos(x/2)),\
      y*sin(x/2)]", "[x, -4, 4]", "[y, -4, 4]",\
                                                                         
                                                 ^
    SyntaxError: unexpected character after line continuation character
**********************************************************************
1 items had failures:
   1 of  57 in interfaces
***Test Failed*** 1 failures.
**********************************************************************
1 items had failures:
   1 of   1 in sage.misc.sh.Sh.eval
***Test Failed*** 1 failures.
**********************************************************************
File "sage.doctest.control", line 246, in sage.doctest.control.DocTestController.add_files
Failed example:
    DC = DocTestController(DD, [])
Exception raised:
    Traceback (most recent call last):
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 573, in _run
        self.execute(example, compiled, test.globs)
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 835, in execute
        exec compiled in globs
      File "<doctest sage.doctest.control.DocTestController.add_files[2]>", line 1, in <module>
        DC = DocTestController(DD, [])
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/control.py", line 127, in __init__
        self.logfile = open(options.logfile, 'a')
    IOError: [Errno 2] No such file or directory: '/release/merger/sage-5.1.beta5-12415/home/.sage//tmp/test.log'
**********************************************************************
File "sage.doctest.control", line 247, in sage.doctest.control.DocTestController.add_files
Failed example:
    DC.add_files()
Exception raised:
    Traceback (most recent call last):
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 573, in _run
        self.execute(example, compiled, test.globs)
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 835, in execute
        exec compiled in globs
      File "<doctest sage.doctest.control.DocTestController.add_files[3]>", line 1, in <module>
        DC.add_files()
    NameError: name 'DC' is not defined
**********************************************************************
File "sage.doctest.control", line 249, in sage.doctest.control.DocTestController.add_files
Failed example:
    (os.path.join(os.environ['SAGE_ROOT'], 'devel', 'sage', 'sage'), True) in DC.files
Exception raised:
    Traceback (most recent call last):
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 573, in _run
        self.execute(example, compiled, test.globs)
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 835, in execute
        exec compiled in globs
      File "<doctest sage.doctest.control.DocTestController.add_files[4]>", line 1, in <module>
        (os.path.join(os.environ['SAGE_ROOT'], 'devel', 'sage', 'sage'), True) in DC.files
    NameError: name 'DC' is not defined
**********************************************************************
File "sage.doctest.control", line 418, in sage.doctest.control.DocTestController.run_doctests
Failed example:
    DC.run_doctests()
Expected:
    Doctesting 1 file.
    sage -t .../sage/rings/homset.py
        [... tests, ... s]
    ------------------------------------------------------------------------
    All tests passed!
    ------------------------------------------------------------------------
    Total time for all tests: ... seconds
        cpu time: ... seconds
        cumulative wall time: ... seconds
Got:
    .
    sage -t /release/merger/sage-5.1.beta5-12415/devel/sage/sage/rings/homset.py
        [15 tests, 0.3 s]
    ------------------------------------------------------------------------
    All tests passed!
    ------------------------------------------------------------------------
    Total time for all tests: 0.8 seconds
        cpu time: 0.1 seconds
        cumulative wall time: 0.3 seconds
**********************************************************************
File "interfaces", line 318, in interfaces
Failed example:
    maxima.plot3d("[cos(x)*(3 + y*cos(x/2)), sin(x)*(3 + y*cos(x/2)),\
      y*sin(x/2)]", "[x, -4, 4]", "[y, -4, 4]",\ 
      '[plot_format, openmath]') # not tested
Exception raised:
    Traceback (most recent call last):
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 572, in _run
        compileflags, 1)
      File "<doctest interfaces[0]>", line 2
        maxima.plot3d("[cos(x)*(3 + y*cos(x/2)), sin(x)*(3 + y*cos(x/2)),\
      y*sin(x/2)]", "[x, -4, 4]", "[y, -4, 4]",\
                                                                         
                                                 ^
    SyntaxError: unexpected character after line continuation character
**********************************************************************
1 items had failures:
   1 of  57 in interfaces
***Test Failed*** 1 failures.
**********************************************************************
File "sage.doctest.control", line 479, in sage.doctest.control.DocTestController.cleanup
Failed example:
    DC.run()
Expected:
    Running doctests with ID ...
    Doctesting 1 file.
    sage -t .../rings/infinity.py
        [... tests, ... s]
    ------------------------------------------------------------------------
    All tests passed!
    ------------------------------------------------------------------------
    Total time for all tests: ... seconds
        cpu time: ... seconds
        cumulative wall time: ... seconds
    0
Got:
    Running doctests with ID 2012-06-25-12-57-35-cf5e164b.
    .
    sage -t /release/merger/sage-5.1.beta5-12415/devel/sage/sage/rings/infinity.py
        [220 tests, 12.8 s]
    ------------------------------------------------------------------------
    All tests passed!
    ------------------------------------------------------------------------
    Total time for all tests: 13.8 seconds
        cpu time: 1.0 seconds
        cumulative wall time: 12.8 seconds
    0
**********************************************************************
File "sage.doctest.control", line 619, in sage.doctest.control.DocTestController.run
Failed example:
    DC.run()
Expected:
    Running doctests with ID ...
    Doctesting 1 file.
    sage -t .../sage/sets/non_negative_integers.py
        [... tests, ... s]
    ------------------------------------------------------------------------
    All tests passed!
    ------------------------------------------------------------------------
    Total time for all tests: ... seconds
        cpu time: ... seconds
        cumulative wall time: ... seconds
    0
Got:
    Running doctests with ID 2012-06-25-12-57-49-f475b4d8.
    .
    sage -t /release/merger/sage-5.1.beta5-12415/devel/sage/sage/sets/non_negative_integers.py
        [41 tests, 0.5 s]
    ------------------------------------------------------------------------
    All tests passed!
    ------------------------------------------------------------------------
    Total time for all tests: 1.4 seconds
        cpu time: 0.1 seconds
        cumulative wall time: 0.5 seconds
    0
**********************************************************************
File "sage.doctest.control", line 660, in sage.doctest.control.run_doctests
Failed example:
    run_doctests(sage.rings.infinity)
Expected:
    Doctesting .../sage/rings/infinity.py
    Running doctests with ID ...
    Doctesting 1 file.
    sage -t .../sage/rings/infinity.py
        [... tests, ... s]
    ------------------------------------------------------------------------
    All tests passed!
    ------------------------------------------------------------------------
    Total time for all tests: ... seconds
        cpu time: ... seconds
        cumulative wall time: ... seconds
Got:
    Doctesting /release/merger/sage-5.1.beta5-12415/devel/sage/sage/rings/infinity.py
    Running doctests with ID 2012-06-25-12-57-50-38f106c7.
    .
    sage -t /release/merger/sage-5.1.beta5-12415/devel/sage/sage/rings/infinity.py
        [220 tests, 20.3 s]
    ------------------------------------------------------------------------
    All tests passed!
    ------------------------------------------------------------------------
    Total time for all tests: 22.3 seconds
        cpu time: 1.0 seconds
        cumulative wall time: 20.3 seconds
**********************************************************************
5 items had failures:
   3 of  13 in sage.doctest.control.DocTestController.add_files
   1 of  10 in sage.doctest.control.DocTestController.cleanup
   1 of   6 in sage.doctest.control.DocTestController.run
   1 of   7 in sage.doctest.control.DocTestController.run_doctests
   1 of   1 in sage.doctest.control.run_doctests
***Test Failed*** 7 failures.
**********************************************************************
File "sage.parallel.decorate", line 559, in sage.parallel.decorate.fork
Failed example:
    g()
Expected:
    <BLANKLINE>
    ------------------------------------------------------------------------
    Unhandled SIGSEGV: A segmentation fault occurred in Sage.
    This probably occurred because a *compiled* component of Sage has a bug
    in it and is not properly wrapped with sig_on(), sig_off(). You might
    want to run Sage under gdb with 'sage -gdb' to debug this.
    Sage will now terminate.
    ------------------------------------------------------------------------
    'NO DATA'
Got:
    /release/merger/sage-5.1.beta5-12415/local/lib/libcsage.so(print_backtrace+0x2b)[0x2b39ebbaf66e]
    /release/merger/sage-5.1.beta5-12415/local/lib/libcsage.so(sigdie+0x14)[0x2b39ebbaf69b]
    /release/merger/sage-5.1.beta5-12415/local/lib/libcsage.so(sage_signal_handler+0x20b)[0x2b39ebbaf189]
    /lib/libpthread.so.0[0x2b39e86417d0]
    /lib/libc.so.6(strlen+0x30)[0x2b39e8f532f0]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyString_FromString+0x1b)[0x2b39e82e486b]
    /release/merger/sage-5.1.beta5-12415/home/.sage//temp/sage.math.washington.edu/28931//spyx//_release_merger_sage_5_1_beta5_12415_home__sage_temp_sage_math_washington_edu_28931_tmp_0_spyx/_release_merger_sage_5_1_beta5_12415_home__sage_temp_sage_math_washington_edu_28931_tmp_0_spyx_0.so[0x2aaaaaab0abd]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x5a63)[0x2b39e833b2a3]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalCodeEx+0x852)[0x2b39e833d312]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0[0x2b39e82c1979]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyObject_Call+0x68)[0x2b39e82942c8]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x37bf)[0x2b39e8338fff]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x69c5)[0x2b39e833c205]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0[0x2b39e82b6b09]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0[0x2b39e82c952d]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0[0x2b39e82c9acb]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0[0x2b39e82f0568]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyObject_Call+0x68)[0x2b39e82942c8]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x1299)[0x2b39e8336ad9]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalCodeEx+0x852)[0x2b39e833d312]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x5ae4)[0x2b39e833b324]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalCodeEx+0x852)[0x2b39e833d312]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalCode+0x32)[0x2b39e833d432]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x714e)[0x2b39e833c98e]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalCodeEx+0x852)[0x2b39e833d312]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x5ae4)[0x2b39e833b324]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x69c5)[0x2b39e833c205]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalCodeEx+0x852)[0x2b39e833d312]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x5ae4)[0x2b39e833b324]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalCodeEx+0x852)[0x2b39e833d312]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0[0x2b39e82c1979]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyObject_Call+0x68)[0x2b39e82942c8]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0[0x2b39e82a487f]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyObject_Call+0x68)[0x2b39e82942c8]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0[0x2b39e82f563a]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyObject_Call+0x68)[0x2b39e82942c8]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x37bf)[0x2b39e8338fff]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x69c5)[0x2b39e833c205]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x69c5)[0x2b39e833c205]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalCodeEx+0x852)[0x2b39e833d312]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0[0x2b39e82c1979]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyObject_Call+0x68)[0x2b39e82942c8]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0[0x2b39e82a487f]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyObject_Call+0x68)[0x2b39e82942c8]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0[0x2b39e82f523c]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0[0x2b39e82f0568]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyObject_Call+0x68)[0x2b39e82942c8]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x1299)[0x2b39e8336ad9]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x69c5)[0x2b39e833c205]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x69c5)[0x2b39e833c205]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x69c5)[0x2b39e833c205]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalCodeEx+0x852)[0x2b39e833d312]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0[0x2b39e82c1979]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyObject_Call+0x68)[0x2b39e82942c8]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0[0x2b39e82a487f]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyObject_Call+0x68)[0x2b39e82942c8]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0[0x2b39e82f523c]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0[0x2b39e82f0568]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyObject_Call+0x68)[0x2b39e82942c8]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x1299)[0x2b39e8336ad9]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x69c5)[0x2b39e833c205]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x69c5)[0x2b39e833c205]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x69c5)[0x2b39e833c205]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x69c5)[0x2b39e833c205]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x69c5)[0x2b39e833c205]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalCodeEx+0x852)[0x2b39e833d312]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyEval_EvalCode+0x32)[0x2b39e833d432]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyRun_FileExFlags+0xc1)[0x2b39e83611b1]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(PyRun_SimpleFileExFlags+0x1f9)[0x2b39e8361489]
    /release/merger/sage-5.1.beta5-12415/local/lib/libpython2.7.so.1.0(Py_Main+0xb15)[0x2b39e8373e65]
    /lib/libc.so.6(__libc_start_main+0xf4)[0x2b39e8ef61f4]
    python[0x400679]
    <BLANKLINE>
    ------------------------------------------------------------------------
    Unhandled SIGSEGV: A segmentation fault occurred in Sage.
    This probably occurred because a *compiled* component of Sage has a bug
    in it and is not properly wrapped with sig_on(), sig_off(). You might
    want to run Sage under gdb with 'sage -gdb' to debug this.
    Sage will now terminate.
    ------------------------------------------------------------------------
    'NO DATA'
**********************************************************************
1 items had failures:
   1 of  17 in sage.parallel.decorate.fork
***Test Failed*** 1 failures.
**********************************************************************
File "sage.tests.startup", line 6, in sage.tests.startup
Failed example:
    if os.uname()[1] == 'sage.math.washington.edu':
        print float(os.popen("sage -startuptime>/dev/null; sage -startuptime|grep sage.all").readlines()[0].split()[1]) < 2.0
    else: print True   # nothing when not on sage.math
Expected:
    True
Got:
    False
**********************************************************************
File "sage.rings.polynomial.multi_polynomial_libsingular", line 420, in sage.rings.polynomial.multi_polynomial_libsingular.MPolynomialRing_libsingular.__copy__
Failed example:
    len(ring_refcount_dict) == n   
Expected:
    True
Got:
    False
**********************************************************************
File "sage.rings.polynomial.plural", line 2738, in sage.rings.polynomial.plural.new_NRing
Failed example:
    z*x
Expected:
    x*z
Got:
    Exception KeyError: (The ring pointer 0x2b3a04886e90,) in 'sage.libs.singular.ring.singular_ring_delete' ignored
    x*z
**********************************************************************
File "sage.rings.polynomial.plural", line 2856, in sage.rings.polynomial.plural.SCA
Failed example:
    E = SCA(QQ, ['x', 'y', 'z'], [0, 1], order = 'degrevlex')
Expected nothing
Got:
    Exception KeyError: (The ring pointer 0x2b3a048af1a0,) in 'sage.libs.singular.ring.singular_ring_delete' ignored
**********************************************************************
File "sage.matrix.benchmark", line 11, in sage.matrix.benchmark
Failed example:
    b.report([b.det_ZZ], 'Test', systems=['sage'])
Expected:
    ======================================================================
              Test
    ======================================================================
    ...
    ======================================================================
Got:
    Linux sage.math.washington.edu 2.6.24-28-server #1 SMP Fri Feb 11 18:08:32 UTC 2011 x86_64 GNU/Linux
    ======================================================================
              Test
    ======================================================================
    <BLANKLINE>
    <BLANKLINE>
    ----------------------------------------------------------------------
    Dense integer determinant over ZZ.
        Given an n x n matrix A over ZZ with random entries
        between min and max, inclusive, compute det(A).
    <BLANKLINE>
   **********************************************************************
2 items had failures:
   1 of   8 in sage.rings.polynomial.plural.SCA
   1 of  17 in sage.rings.polynomial.plural.new_NRing
***Test Failed*** 2 failures.
     INPUT:
    <BLANKLINE>
        - ``n`` - matrix dimension (default: ``200``)
        - ``min`` - minimal value for entries of matrix (default: ``1``)
        - ``max`` - maximal value for entries of matrix (default: ``100``)
        - ``system`` - either 'sage' or 'magma' (default: 'sage')
    <BLANKLINE>
        EXAMPLES::
    <BLANKLINE>
            sage: import sage.matrix.benchmark as b
            sage: ts = b.det_ZZ(200)
            sage: tm = b.det_ZZ(200, system='magma')  # optional - magma
               sage
              1.560
    ======================================================================
**********************************************************************
1 items had failures:
   1 of  16 in sage.rings.polynomial.multi_polynomial_libsingular.MPolynomialRing_libsingular.__copy__
***Test Failed*** 1 failures.
**********************************************************************
1 items had failures:
   1 of   2 in sage.tests.startup
***Test Failed*** 1 failures.
**********************************************************************
File "sage.matrix.benchmark", line 38, in sage.matrix.benchmark.report
Failed example:
    b.report([b.det_ZZ], 'Test', systems=['sage'])
Expected:
    ======================================================================
              Test
    ======================================================================
    ...
    ======================================================================
Got:
    Linux sage.math.washington.edu 2.6.24-28-server #1 SMP Fri Feb 11 18:08:32 UTC 2011 x86_64 GNU/Linux
    ======================================================================
              Test
    ======================================================================
    <BLANKLINE>
    <BLANKLINE>
    ----------------------------------------------------------------------
    Dense integer determinant over ZZ.
        Given an n x n matrix A over ZZ with random entries
        between min and max, inclusive, compute det(A).
    <BLANKLINE>
        INPUT:
    <BLANKLINE>
        - ``n`` - matrix dimension (default: ``200``)
        - ``min`` - minimal value for entries of matrix (default: ``1``)
        - ``max`` - maximal value for entries of matrix (default: ``100``)
        - ``system`` - either 'sage' or 'magma' (default: 'sage')
    <BLANKLINE>
        EXAMPLES::
    <BLANKLINE>
            sage: import sage.matrix.benchmark as b
            sage: ts = b.det_ZZ(200)
            sage: tm = b.det_ZZ(200, system='magma')  # optional - magma
               sage
              1.330
    ======================================================================
**********************************************************************
File "sage.doctest.forker", line 925, in sage.doctest.forker.SageDocTestRunner.report_unexpected_exception
Failed example:
    "ArithmeticError" in tb
Expected:
    True
Got:
    False
**********************************************************************
File "sage.doctest.forker", line 1185, in sage.doctest.forker.DocTestWorker.__init__
Failed example:
    run_doctests(sage.rings.big_oh) # indirect doctest
Expected:
    Doctesting .../sage/rings/big_oh.py
    Running doctests with ID ...
    Doctesting 1 file.
    sage -t .../sage/rings/big_oh.py
        [... tests, ... s]
    ------------------------------------------------------------------------
    All tests passed!
    ------------------------------------------------------------------------
    Total time for all tests: ... seconds
        cpu time: ... seconds
        cumulative wall time: ... seconds
Got:
    Doctesting /release/merger/sage-5.1.beta5-12415/devel/sage/sage/rings/big_oh.py
    Running doctests with ID 2012-06-25-12-59-29-e5a039b5.
    .
    sage -t /release/merger/sage-5.1.beta5-12415/devel/sage/sage/rings/big_oh.py
        [17 tests, 1.4 s]
    ------------------------------------------------------------------------
    All tests passed!
    ------------------------------------------------------------------------
    Total time for all tests: 1.9 seconds
        cpu time: 0.4 seconds
        cumulative wall time: 1.4 seconds
**********************************************************************
File "sage.doctest.forker", line 1211, in sage.doctest.forker.DocTestWorker.run
Failed example:
    run_doctests(sage.symbolic.units) # indirect doctest
Expected:
    Doctesting .../sage/symbolic/units.py
    Running doctests with ID ...
    Doctesting 1 file.
    sage -t .../sage/symbolic/units.py
        [... tests, ... s]
    ------------------------------------------------------------------------
    All tests passed!
    ------------------------------------------------------------------------
    Total time for all tests: ... seconds
        cpu time: ... seconds
        cumulative wall time: ... seconds
Got:
    Doctesting /release/merger/sage-5.1.beta5-12415/devel/sage/sage/symbolic/units.py
    Running doctests with ID 2012-06-25-12-59-31-e804e534.
    .
    sage -t /release/merger/sage-5.1.beta5-12415/devel/sage/sage/symbolic/units.py
        [82 tests, 0.4 s]
    ------------------------------------------------------------------------
    All tests passed!
    ------------------------------------------------------------------------
    Total time for all tests: 0.7 seconds
        cpu time: 0.2 seconds
        cumulative wall time: 0.4 seconds
**********************************************************************
3 items had failures:
   1 of   1 in sage.doctest.forker.DocTestWorker.__init__
   1 of   1 in sage.doctest.forker.DocTestWorker.run
   1 of  18 in sage.doctest.forker.SageDocTestRunner.report_unexpected_exception
***Test Failed*** 3 failures.
**********************************************************************
File "sage.tests.cmdline", line 270, in sage.tests.cmdline.test_executable
Failed example:
    ret
Expected:
    0
Got:
    1
**********************************************************************
File "sage.tests.cmdline", line 272, in sage.tests.cmdline.test_executable
Failed example:
    out.find("All tests passed!") >= 0
Expected:
    True
Got:
    False
**********************************************************************
File "sage.tests.cmdline", line 275, in sage.tests.cmdline.test_executable
Failed example:
    ret
Expected:
    0
Got:
    1
**********************************************************************
File "sage.tests.cmdline", line 277, in sage.tests.cmdline.test_executable
Failed example:
    out.find("All tests passed!") >= 0
Expected:
    True
Got:
    False
**********************************************************************
File "sage.tests.cmdline", line 291, in sage.tests.cmdline.test_executable
Failed example:
    ret
Expected:
    128
Got:
    1
**********************************************************************
File "sage.tests.cmdline", line 293, in sage.tests.cmdline.test_executable
Failed example:
    out.find("1 items had failures:") >= 0
Expected:
    True
Got:
    False
**********************************************************************
1 items had failures:
   6 of 183 in sage.tests.cmdline.test_executable
***Test Failed*** 6 failures.
**********************************************************************
File "sage.matrix.benchmark", line 566, in sage.matrix.benchmark.report_GF
Failed example:
    b.report_GF(systems=['sage'])
Expected:
    ======================================================================
    Dense benchmarks over GF with prime 16411
    ======================================================================
    ...
    ======================================================================
Got:
    Linux sage.math.washington.edu 2.6.24-28-server #1 SMP Fri Feb 11 18:08:32 UTC 2011 x86_64 GNU/Linux
    ======================================================================
              Dense benchmarks over GF with prime 16411
    ======================================================================
    <BLANKLINE>
    <BLANKLINE>
    ----------------------------------------------------------------------
    Rank over GF(p):
        Given a n x (n+10) matrix over GF(p) with random entries, compute the rank.
    <BLANKLINE>
        INPUT:
    <BLANKLINE>
        - ``n`` - matrix dimension (default: 300)
        - ``p`` - prime number (default: ``16411``)
        - ``system`` - either 'magma' or 'sage' (default: 'sage')
    <BLANKLINE>
        EXAMPLES::
    <BLANKLINE>
            sage: import sage.matrix.benchmark as b
            sage: ts = b.rank_GF(1000)
            sage: tm = b.rank_GF(1000, system='magma')  # optional - magma
               sage
              0.160
    ----------------------------------------------------------------------
    Rank over GF(p): Given a (n + 10) x n matrix over GF(p) with
        random entries, compute the rank.
    <BLANKLINE>
        INPUT:
    <BLANKLINE>
        - ``n`` - matrix dimension (default: 300)
        - ``p`` - prime number (default: ``16411``)
        - ``system`` - either 'magma' or 'sage' (default: 'sage')
    <BLANKLINE>
        EXAMPLES::
    <BLANKLINE>
            sage: import sage.matrix.benchmark as b
            sage: ts = b.rank2_GF(500)
            sage: tm = b.rank2_GF(500, system='magma')  # optional - magma
               sage
              0.170
    ----------------------------------------------------------------------
    Given a n+1 x n  matrix over GF(p) with random
        entries, compute the nullspace.
    <BLANKLINE>
        INPUT:
    <BLANKLINE>
        - ``n`` - matrix dimension (default: 300)
        - ``p`` - prime number (default: ``16411``)
        - ``system`` - either 'magma' or 'sage' (default: 'sage')
    <BLANKLINE>
        EXAMPLES::
    <BLANKLINE>
            sage: import sage.matrix.benchmark as b
            sage: ts = b.nullspace_GF(300)
            sage: tm = b.nullspace_GF(300, system='magma')  # optional - magma
               sage
              0.820
    ----------------------------------------------------------------------
    Given a n x n matrix over GF with random entries, compute the
        charpoly.
    <BLANKLINE>
        INPUT:
    <BLANKLINE>
        - ``n`` - matrix dimension (default: 100)
        - ``p`` - prime number (default: ``16411``)
        - ``system`` - either 'magma' or 'sage' (default: 'sage')
    <BLANKLINE>
        EXAMPLES::
    <BLANKLINE>
            sage: import sage.matrix.benchmark as b
            sage: ts = b.charpoly_GF(100)
            sage: tm = b.charpoly_GF(100, system='magma')  # optional - magma
               sage
              0.060
    ----------------------------------------------------------------------
    Given an n x n matrix A over GF(p) with random entries, compute
        A * (A+1).
    <BLANKLINE>
        INPUT:
    <BLANKLINE>
        - ``n`` - matrix dimension (default: 100)
        - ``p`` - prime number (default: ``16411``)
        - ``system`` - either 'magma' or 'sage' (default: 'sage')
        - ``times`` - number of experiments (default: ``3``)
    <BLANKLINE>
        EXAMPLES::
    <BLANKLINE>
            sage: import sage.matrix.benchmark as b
            sage: ts = b.matrix_multiply_GF(100, p=19)
            sage: tm = b.matrix_multiply_GF(100, p=19, system='magma')  # optional - magma
               sage
              0.003
    ----------------------------------------------------------------------
    Dense determinant over GF(p).
        Given an n x n matrix A over GF with random entries compute
        det(A).
    <BLANKLINE>
        INPUT:
    <BLANKLINE>
        - ``n`` - matrix dimension (default: 300)
        - ``p`` - prime number (default: ``16411``)
        - ``system`` - either 'magma' or 'sage' (default: 'sage')
    <BLANKLINE>
        EXAMPLES::
    <BLANKLINE>
            sage: import sage.matrix.benchmark as b
            sage: ts = b.det_GF(1000)
            sage: tm = b.det_GF(1000, system='magma')  # optional - magma
               sage
              0.090
    ======================================================================
**********************************************************************
3 items had failures:
   1 of   2 in sage.matrix.benchmark
   1 of   2 in sage.matrix.benchmark.report
   1 of   2 in sage.matrix.benchmark.report_GF
***Test Failed*** 3 failures.

------------------------------------------------------------------------
Doctests interrupted: 0/2067 files tested
------------------------------------------------------------------------
Total time for all tests: 181.4 seconds
    cpu time: 0.0 seconds
    cumulative wall time: 0.0 seconds
Traceback (most recent call last):
  File "/release/merger/sage-5.1.beta5-12415/local/bin/sage-runtests", line 69, in <module>
    err = DC.run()
  File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/control.py", line 645, in run
    self.run_doctests()
  File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/control.py", line 446, in run_doctests
    self.dispatcher.dispatch()
  File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 1130, in dispatch
    self._parallel_dispatch()
  File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 1072, in _parallel_dispatch
    w.start()
  File "/release/merger/sage-5.1.beta5-12415/local/lib/python/multiprocessing/process.py", line 130, in start
    self._popen = Popen(self)
  File "/release/merger/sage-5.1.beta5-12415/local/lib/python/multiprocessing/forking.py", line 120, in __init__
    self.pid = os.fork()
OSError: [Errno 12] Cannot allocate memory

[jdemeyer]

Replying to jdemeyer:

Planning to make a reviewer patch

...after you guys fix the more serious errors.

[roed]

Some of these are due to a bug in the change I just made to -p. I'm working on fixing those.

Some look like you didn't apply the patch to the sagenb repo. Did you forget, or is something else going on?

Some are due to the fact that in your tests, os.system calls are happening before the python process gets far enough, so results that were printed to the screen in the wrong order. I'm guessing this may relate to the fact that you're running on /release, since my tests on sage.math didn't show the same behavior.

I'm in the process of fixing stuff.

[roed]

There's some code in the current doctesting code to output xml results, which I'm not currently duplicating. Is this used somewhere?

[roed]

Currently sage -t --new is broken. I'm trying to figure out why.

[roed]

Alright, I'm going to start running tests. There are still some remaining issues, but the patches are in a state where someone else might want to look at them. :-)

Remaining problems:

• #13145 needs work, generating some doctest failures related to deallocating multivariate polynomials
• hg_sage seems to be broken, causing the --new option to fail
• valgrinding sage -t doesn't work; I'm not sure whether it did before
• The new code doesn't support xml output

I'll see if I find more when running sage -t --all.

[jdemeyer]

Replying to roed:

Some are due to the fact that in your tests, os.system calls are happening before the python process gets far enough, so results that were printed to the screen in the wrong order.

Use sys.stdout.flush() (and/or the same for stderr) before os.system() to overcome this. The difference is probably that my output was sent to a pipe, as opposed to directly to the terminal. In the latter case, flushing is automatic.

True, I might not have applied all patches correctly.

[kini]

It doesn't make sense to patch the old notebook. Please work with the flask notebook instead (i.e. make this ticket depend on #11080 and preferably #13121).

[roed]

Replying to kini:

It doesn't make sense to patch the old notebook. Please work with the flask notebook instead (i.e. make this ticket depend on #11080 and preferably #13121).

I agree that it doesn't make much sense to patch the old notebook, but if this can get a positive review quickly I'd rather not wait on #11080 and #13121. The changes to the old notebook are pretty minor.

[roed]

Design question: when running tests in parallel, failed examples are printed as they arise, meaning that examples from different files are intermingled. Is this a problem that needs to be fixed?

[roed]

The only tests I have failing on sage.math are sage.tests.startup and sage.rings.polynomial.multi_polynomial_libsingular (due to #13145).

[jdemeyer]

Replying to roed:

Design question: when running tests in parallel, failed examples are printed as they arise, meaning that examples from different files are intermingled. Is this a problem that needs to be fixed?

It might not be truly a problem, but I prefer the current model where the tests for one file are grouped.

[jdemeyer]

Replying to roed:

Design question: when running tests in parallel, failed examples are printed as they arise, meaning that examples from different files are intermingled. Is this a problem that needs to be fixed?

Even better might be an option to show only the first failure in each file.

[roed]

I've updated the code to group results for each file, and added an option (sage -t --initial) so that only the first failure is reported.

[jdemeyer]

The following is cut from a make ptestlong run:

sage -t devel/sage/sage/symbolic/expression.pyx
    [1960 tests, 38.2 s]
sage -t devel/sage/sage/pl**********************************************************************
File "sage.schemes.elliptic_curves.ell_rational_field", line 1468, in sage.schemes.elliptic_curves.ell_rational_field.EllipticCurve_ration
al_field.simon_two_descent
Failed example:
    E.simon_two_descent()  # long time (9s on sage.math, 2011)
Expected:
    (5, 5, [(5 : 8 : 1), (4 : 9 : 1), (3 : 11 : 1), (-1 : 20 : 1), (-6 : -25 : 1)])
Got:
    Saturation index bound = 265
    WARNING: saturation at primes p > 97 will not be done;
    points may be unsaturated at primes between 97 and index bound
    Failed to saturate MW basis at primes [ ]
    Saturation index bound = 265
    WARNING: saturation at primes p > 199 will not be done;
    points may be unsaturated at primes between 199 and index bound
    Failed to saturate MW basis at primes [ ]
    (5, 5, [(5 : 8 : 1), (4 : 9 : 1), (3 : 11 : 1), (-1 : 20 : 1), (-6 : -25 : 1)])
**********************************************************************
1 items had failures:
   1 of  38 in sage.schemes.elliptic_curves.ell_rational_field.EllipticCurve_rational_field.simon_two_descent
***Test Failed*** 1 failures.
ot/plot3d/implicit_plot3d.py
    [57 tests, 26.9 s]
sage -t devel/sage/sage/modular/modsym/ambient.py
    [397 tests, 26.4 s]

There are 3 issues:

1. The doctest failure itself.

2. The fact that sage -t foo is written instead of sage -t --long foo.

3. Output flushing: note the

   sage -t devel/sage/sage/pl
   

and then later

ot/plot3d/implicit_plot3d.py
    [57 tests, 26.9 s]

By all means please keep working on this, it already looks very cool!

[jdemeyer]

Some more doctest failures from make ptest:

sage -t devel/sage/doc/common/__init__.py
    [0 tests, 0.0 s]
sage -t devel/sage/doc/common/build_optiUsage: sage -docbuild [OPTIONS] DOCUMENT (FORMAT | COMMAND)

sage-runtests: error: no such option: -p
ons.py
    [0 tests, 0.0 s]
sage -t devel/sage/doc/common/builder.py
    Bad exit: 2
Tests run before process failed:

sage -t devel/sage/doc/common/conf.py
    [0 tests, 0.0 s]

sage -t devel/sage/doc/de/tutorial/interactive_shell.rst
    Error: TAB character found at line 656
    [8 tests, 0.2 s]
sage -t devel/sage/doc/en/tutorial/interactive_shell.rst
    [8 tests, 0.2 s]
sage -t devel/sage/doc/en/bordeaux_2008/birds_other.rst
    [26 tests, 5.2**********************************************************************
File "interfaces", line 331, in interfaces
Failed example:
    maxima.plot3d("[cos(x)*(3 + y*cos(x/2)), sin(x)*(3 + y*cos(x/2)),\
      y*sin(x/2)]", "[x, -4, 4]", "[y, -4, 4]",\
      '[plot_format, openmath]') # not tested
Exception raised:
    Traceback (most recent call last):
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 590, in _run
        compileflags, 1)
      File "<doctest interfaces[0]>", line 2
        maxima.plot3d("[cos(x)*(3 + y*cos(x/2)), sin(x)*(3 + y*cos(x/2)),\
      y*sin(x/2)]", "[x, -4, 4]", "[y, -4, 4]",\

                                                 ^
    SyntaxError: unexpected character after line continuation character
**********************************************************************
1 items had failures:
   1 of  57 in interfaces
***Test Failed*** 1 failures.
**********************************************************************
File "interfaces", line 318, in interfaces
Failed example:
    maxima.plot3d("[cos(x)*(3 + y*cos(x/2)), sin(x)*(3 + y*cos(x/2)),\
      y*sin(x/2)]", "[x, -4, 4]", "[y, -4, 4]",\
      '[plot_format, openmath]') # not tested
Exception raised:
    Traceback (most recent call last):
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 590, in _run
        compileflags, 1)
      File "<doctest interfaces[0]>", line 2
        maxima.plot3d("[cos(x)*(3 + y*cos(x/2)), sin(x)*(3 + y*cos(x/2)),\
      y*sin(x/2)]", "[x, -4, 4]", "[y, -4, 4]",\

                                                 ^
    SyntaxError: unexpected character after line continuation character
**********************************************************************
1 items had failures:
   1 of  57 in interfaces
***Test Failed*** 1 failures.
 s]
sage -t devel/sage/doc/fr/tutorial/interactive_shell.rst
    [8 tests, 0.2 s]

(why is the filename simply "interfaces")

sage -t devel/sage/doc/en/reference/probability.rst
    [0 tests, 0.0 s]
sage -t de**********************************************************************
File "programming", line 620, in programming
Failed example:
    for i in range(5):
Exception raised:
    Traceback (most recent call last):
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 590, in _run
        compileflags, 1)
      File "<doctest programming[0]>", line 1
        for i in range(5):
                         ^
    SyntaxError: unexpected EOF while parsing
**********************************************************************
1 items had failures:
   1 of 113 in programming
***Test Failed*** 1 failures.

sage -t devel/sage/doc/en/reference/rings_standard.rst
    [0 tests, 0.0 s]
sage -t devel/sage/doc/en/reference/combinat/root_syste**********************************************************************
File "programming", line 578, in programming
Failed example:
    for i in range(5):
Exception raised:
    Traceback (most recent call last):
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 590, in _run
        compileflags, 1)
      File "<doctest programming[0]>", line 1
        for i in range(5):
                         ^
    SyntaxError: unexpected EOF while parsing
**********************************************************************
1 items had failures:
   1 of 113 in programming
***Test Failed*** 1 failures.
ms.rst
    [0 tests, 0.0 s]

sage -t devel/sage/sage/databases/odlyzko.py
    [0 tests, 0.0 s]
sag**********************************************************************
File "sage.doctest.reporting", line 93, in sage.doctest.reporting.DocTestReporter.report
Failed example:
    DTR.report(FDS, True, 0, None, "Output so far...")
Expected:
    sage -t .../devel/sage/sage/doctest/reporting.py
        Timed out!
    Output so far...
Got:
    sage -t /release/merger/sage-5.1.beta5-12415/devel/sage/sage/doctest/reporting.py
        Timed out!
    Tests run before process froze:
    Output so far...
**********************************************************************
File "sage.doctest.reporting", line 102, in sage.doctest.reporting.DocTestReporter.report
Failed example:
    DTR.report(FDS, False, 3, None, "Output before bad exit")
Expected:
    sage -t .../devel/sage/sage/doctest/reporting.py
        Bad exit: 3
    Output before bad exit
Got:
    sage -t /release/merger/sage-5.1.beta5-12415/devel/sage/sage/doctest/reporting.py
        Bad exit: 3
    Tests run before process failed:
    Output before bad exit
**********************************************************************
File "sage.doctest.reporting", line 215, in sage.doctest.reporting.DocTestReporter.finalize
Failed example:
    DTR.report(FDS, True, 0, None, "Output so far...")
Expected:
    sage -t .../devel/sage/sage/doctest/reporting.py
        Timed out!
    Output so far...
Got:
    sage -t /release/merger/sage-5.1.beta5-12415/devel/sage/sage/doctest/reporting.py
        Timed out!
    Tests run before process froze:
    Output so far...
**********************************************************************
File "sage.doctest.reporting", line 219, in sage.doctest.reporting.DocTestReporter.finalize
Failed example:
    DTR.report(FDS, False, 3, None, "Output before bad exit")
Expected:
    sage -t .../devel/sage/sage/doctest/reporting.py
        Bad exit: 3
    Output before bad exit
Got:
    sage -t /release/merger/sage-5.1.beta5-12415/devel/sage/sage/doctest/reporting.py
        Bad exit: 3
    Tests run before process failed:
    Output before bad exit
**********************************************************************
2 items had failures:
   2 of  26 in sage.doctest.reporting.DocTestReporter.finalize
   2 of  23 in sage.doctest.reporting.DocTestReporter.report
***Test Failed*** 4 failures.
e -t devel/sage/sage/databases/sloane.py
    [1 tests, 0.1 s]

sage -t devel/sage/sage/ext/cdefs.pxi
    [0 tests, 0.0 s]
sage -t devel/sage/sage/docte**********************************************************************
File "sage.doctest.control", line 252, in sage.doctest.control.DocTestController.add_files
Failed example:
    DC = DocTestController(DD, [])
Exception raised:
    Traceback (most recent call last):
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 591, in _run
        self.execute(example, compiled, test.globs)
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 873, in execute
        exec compiled in globs
      File "<doctest sage.doctest.control.DocTestController.add_files[2]>", line 1, in <module>
        DC = DocTestController(DD, [])
      File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/control.py", line 132, in __init__
        print "Unable to open logfile at %s\nProceeding without logging."%(self.logfile)
    AttributeError: 'DocTestController' object has no attribute 'logfile'
**********************************************************************

sage -t devel/sage/sage/misc/profiler.py
    [0 tests, 0.0 s]
sage -t devel/sage/**********************************************************************
File "sage.matrix.benchmark", line 11, in sage.matrix.benchmark
Failed example:
    print "starting"; b.report([b.det_ZZ], 'Test', systems=['sage'])
Expected:
    starting...
    ======================================================================
              Test
    ======================================================================
    ...
    ======================================================================
Got:
    Linux sage.math.washington.edu 2.6.24-28-server #1 SMP Fri Feb 11 18:08:32 UTC 2011 x86_64 GNU/Linux
    starting
    ======================================================================
              Test
    ======================================================================
    <BLANKLINE>
    <BLANKLINE>
    ----------------------------------------------------------------------
    Dense integer determinant over ZZ.
        Given an n x n matrix A over ZZ with random entries
        between min and max, inclusive, compute det(A).
    <BLANKLINE>
        INPUT:
    <BLANKLINE>
        - ``n`` - matrix dimension (default: ``200``)
        - ``min`` - minimal value for entries of matrix (default: ``1``)
        - ``max`` - maximal value for entries of matrix (default: ``100``)
        - ``system`` - either 'sage' or 'magma' (default: 'sage')
    <BLANKLINE>
        EXAMPLES::
    <BLANKLINE>
            sage: import sage.matrix.benchmark as b
            sage: ts = b.det_ZZ(200)
            sage: tm = b.det_ZZ(200, system='magma')  # optional - magma
               sage
              1.370
    ======================================================================
**********************************************************************

[jdemeyer]

Another annoyance, compare in the output:

sage -t devel/sage/sage/rings/polynomial/padics/polynomial_padic_capped_relative_dense.py

sage -t /release/merger/sage-5.1.beta5-12415/devel/sagenb-main/sagenb/interfaces/expect.py

Why a relative path in the first case but a full path in the second case? Also with -a, only absolute paths are shown. I would prefer all paths to be relative to the current directory.

[jdemeyer]

jdemeyer@sage:/release/merger/sage-5.1.beta5-12415$ ./sage -tp 1000000000 devel/sage/sage/rings/padics/
Running doctests with ID 2012-06-26-11-58-02-3accd40f.
Doctesting 32 files using 1000000000 threads

The previous doctester would reduce the number of threads to be at most the number of files to test.

[jdemeyer]

A very useful feature from the previous doctester which is missing here is that --verbose actually shows the output as the test is running. So when it gets stuck somewhere, you actually see that it gets stuck. Currently, the whole test result is simply dumped at the end.

Also: previously, line numbers were shown with --verbose (albeit in a very bad way).

One more feature-request: with --verbose, show the time taken for each single test, i.e. I would like

Trying (line 242):
    EllipticCurve('900d1').integral_points()
Expecting:
    [(-11 : 27 : 1), (-4 : 34 : 1), (4 : 18 : 1), (16 : 54 : 1)]
ok [0.10s]
Trying (line 243):
    E=EllipticCurve([-879984,319138704])
Expecting nothing
ok [1.92s]
Trying (line 255):
    P1=E.point((540,1188)); P2=E.point((576,1836))
Expecting nothing
ok [4.59s]

It's totally okay for me to disallow --verbose in parallel tests.

[jdemeyer]

What does the --serial option do and how is it different from -p 1?

[jdemeyer]

I would expect sage -t -f not to need any filename arguments (similarly to -a), just run all the failed tests.

However:

jdemeyer@sage:/release/merger/sage-5.1.beta5-12415$ ./sage -t -f
Usage: sage -t [options] filenames

[jdemeyer]

Perhaps add a -T option as a synonym for --timeout?

[jdemeyer]

I'm collecting some "special cases" for doctests in ​http://boxen.math.washington.edu/home/jdemeyer/doctest/ (maybe these should eventually become "meta-doctests").

The doctesting framework seems to hang on

jdemeyer@sage:/release/merger/sage-5.1.beta5-12415$ ./sage -t /home/jdemeyer/doctest/sigdie.py
Running doctests with ID 2012-06-26-14-12-55-fbefc7c4.
Doctesting 1 file.

While the following gives an error inside the doctesting framework (this also used to fail before):

jdemeyer@sage:/release/merger/sage-5.1.beta5-12415$ ./sage -t /home/jdemeyer/doctest/keyboardinterrupt.py
Running doctests with ID 2012-06-26-14-12-38-b70e54c4.
Doctesting 1 file.
sage -t /home/jdemeyer/doctest/keyboardinterrupt.py
Traceback (most recent call last):
  File "/release/merger/sage-5.1.beta5-12415/local/lib/python2.7/site-packages/sage/doctest/reporting.py", line 146, in report
    ntests, runner = results
TypeError: 'NoneType' object is not iterable

------------------------------------------------------------------------
Doctests interrupted: 0/1 files tested
------------------------------------------------------------------------
Total time for all tests: 1.0 seconds
    cpu time: 0.0 seconds
    cumulative wall time: 0.0 seconds

The following should report an error but doesn't:

jdemeyer@sage:/release/merger/sage-5.1.beta5-12415$ ./sage -t /home/jdemeyer/doctest/sig_on.py
Running doctests with ID 2012-06-26-14-14-08-06a01dbf.
Doctesting 1 file.
sage -t /home/jdemeyer/doctest/sig_on.py
    [1 tests, 1.1 s]
------------------------------------------------------------------------
All tests passed!
------------------------------------------------------------------------
Total time for all tests: 2.1 seconds
    cpu time: 0.1 seconds
    cumulative wall time: 1.1 seconds

[roed]

I'm working on fixing these. Thanks for the feedback!

[roed]

Replying to jdemeyer:

What does the --serial option do and how is it different from -p 1?

The -p 1 has one worker: there's another thread which collates and prints answers. -p 1 is the default.

[roed]

Replying to jdemeyer:

Perhaps add a -T option as a synonym for --timeout?

Done. Are there other options that should have a short form? Maybe -L for --long? I'd like to avoid too much mixing of upper and lower case....

[roed]

There doesn't seem to be an objection to diverting stderr, so I'm going to not worry about keeping changes resulting from that decision separate (I don't want to update that patch since it requires rebuilding a lot of files).

[roed]

Replying to jdemeyer:

The following should report an error but doesn't:

jdemeyer@sage:/release/merger/sage-5.1.beta5-12415$ ./sage -t /home/jdemeyer/doctest/sig_on.py
Running doctests with ID 2012-06-26-14-14-08-06a01dbf.
Doctesting 1 file.
sage -t /home/jdemeyer/doctest/sig_on.py
    [1 tests, 1.1 s]
------------------------------------------------------------------------
All tests passed!
------------------------------------------------------------------------
Total time for all tests: 2.1 seconds
    cpu time: 0.1 seconds
    cumulative wall time: 1.1 seconds

If I do cython('sig_on()') at the command line nothing happens. Is it supposed to crash Sage?

[roed]

Replying to roed:

Replying to jdemeyer:

The following should report an error but doesn't:

jdemeyer@sage:/release/merger/sage-5.1.beta5-12415$ ./sage -t /home/jdemeyer/doctest/sig_on.py
Running doctests with ID 2012-06-26-14-14-08-06a01dbf.
Doctesting 1 file.
sage -t /home/jdemeyer/doctest/sig_on.py
    [1 tests, 1.1 s]
------------------------------------------------------------------------
All tests passed!
------------------------------------------------------------------------
Total time for all tests: 2.1 seconds
    cpu time: 0.1 seconds
    cumulative wall time: 1.1 seconds

If I do cython('sig_on()') at the command line nothing happens. Is it supposed to crash Sage?

I can even run sage commands afterward, like factor(2^199-1). But if I hit Ctl-C, I get a segfault (and it screws up my terminal).

[roed]

New version posted. sage -t --long -a passes all tests except the one related to #13145.

/home/jdemeyer/doctest/keyboardinterrupt.py passes if you remove the trailing colon. I've updated the framework to recover a bit more gracefully if a doctest raises an unexpected KeyboardInterrupt?, but it behaves a bit strangely since it's difficult to distinguish between an actual interrupt (in which case the testing should terminate) and one raised by a doctest (in which case tests of other files could continue). I think the new behavior is actually fairly reasonable: try it on your file without removing the colon.

[roed]

Replying to jdemeyer:

The doctesting framework seems to hang on

jdemeyer@sage:/release/merger/sage-5.1.beta5-12415$ ./sage -t /home/jdemeyer/doctest/sigdie.py
Running doctests with ID 2012-06-26-14-12-55-fbefc7c4.
Doctesting 1 file.

Is this behavior acceptable? Eventually the test will time out (you can try running sage -t -T 5 /home/jdemeyer/doctest/sigdie.py) and the ending summary will be printed with a time out.

[jdemeyer]

Replying to roed:

it's difficult to distinguish between an actual interrupt (in which case the testing should terminate) and one raised by a doctest (in which case tests of other files could continue).

A "real" interrupt would interrupt also the master process, a fake doctest-interrupt only the child process. That's an easy way to distinguish.

[jdemeyer]

Replying to roed:

Replying to jdemeyer:

The doctesting framework seems to hang on

jdemeyer@sage:/release/merger/sage-5.1.beta5-12415$ ./sage -t /home/jdemeyer/doctest/sigdie.py
Running doctests with ID 2012-06-26-14-12-55-fbefc7c4.
Doctesting 1 file.

Is this behavior acceptable?

Not really. One should get a message that Sage crashed (compare with the old doctesting framework).

[jdemeyer]

Replying to roed:

If I do cython('sig_on()') at the command line nothing happens. Is it supposed to crash Sage?

Let me elaborate: #10030 added a check to the doctesting code which checks

sage: sig_on_count()
0

after each doctest (i.e. it appends this to every doctest), to ensure there are no unbalanced sig_on()s. Could you add this also to your doctesting framework?

[roed]

Replying to jdemeyer:

Replying to roed:

it's difficult to distinguish between an actual interrupt (in which case the testing should terminate) and one raised by a doctest (in which case tests of other files could continue).

A "real" interrupt would interrupt also the master process, a fake doctest-interrupt only the child process. That's an easy way to distinguish.

Sure, and for reporting what happened to the user this is fine. But from the child process' perspective, an unexpected KeyboardInterrupt has been raised and it should stop testing that file. The parent process can continue the doctests though....

[roed]

Replying to jdemeyer:

Replying to roed:

Replying to jdemeyer:

The doctesting framework seems to hang on

jdemeyer@sage:/release/merger/sage-5.1.beta5-12415$ ./sage -t /home/jdemeyer/doctest/sigdie.py
Running doctests with ID 2012-06-26-14-12-55-fbefc7c4.
Doctesting 1 file.

Is this behavior acceptable?

Not really. One should get a message that Sage crashed (compare with the old doctesting framework).

Okay, I will look into it. I assume that the underlying process has terminated and I should be able to get at the exit code somehow.

[roed]

Replying to jdemeyer:

Replying to roed:

If I do cython('sig_on()') at the command line nothing happens. Is it supposed to crash Sage?

Let me elaborate: #10030 added a check to the doctesting code which checks

sage: sig_on_count()
0

after each doctest (i.e. it appends this to every doctest), to ensure there are no unbalanced sig_on()s. Could you add this also to your doctesting framework?

This shouldn't be too hard.

[roed]

Replying to roed:

Alright, I'm going to start running tests. There are still some remaining issues, but the patches are in a state where someone else might want to look at them. :-)

Remaining problems:

• #13145 needs work, generating some doctest failures related to deallocating multivariate polynomials
• hg_sage seems to be broken, causing the --new option to fail
• valgrinding sage -t doesn't work; I'm not sure whether it did before
• The new code doesn't support xml output

I'll see if I find more when running sage -t --all.

I'm going to sleep; let me know which of these need to be fixed in order for this ticket to get a positive review. I will also keep working on the tests in /home/jdemeyer/doctest/. And of course if you find more problems or have other feature requests, keep those coming too!

[jdemeyer]

Replying to roed:

Sure, and for reporting what happened to the user this is fine. But from the child process' perspective, an unexpected KeyboardInterrupt has been raised and it should stop testing that file.

Okay, I see what you mean. I would propose not to special-case KeyboardInterrupt at all in the child process. When the parent process gets a KeyboardInterrupt, kill all child processes (without showing their output) and exit.

(note: since the old doctesting framework didn't do this either, I don't consider this a prerequisite for positive review, but a nice feature to have.)

[jdemeyer]

Replying to roed:

Replying to jdemeyer:

What does the --serial option do and how is it different from -p 1?

The -p 1 has one worker: there's another thread which collates and prints answers. -p 1 is the default.

I suppose you mean "process", not thread? Still, I don't see the point of --serial.

[roed]

Replying to jdemeyer:

Replying to roed:

Replying to jdemeyer:

What does the --serial option do and how is it different from -p 1?

The -p 1 has one worker: there's another thread which collates and prints answers. -p 1 is the default.

I suppose you mean "process", not thread? Still, I don't see the point of --serial.

The main point of --serial is that it allows you to debug problems in the doctesting framework without worrying about multiprocessing. :-)

I'm fine making it less prominent (having it not show up in the help display for sage -t for example, and not using it for --verbose mode). But I think it should stick around since it currently exists, and it makes some kinds of bugs much easier to track down.

[roed]

Replying to roed:

Replying to jdemeyer:

Replying to roed:

Replying to jdemeyer:

What does the --serial option do and how is it different from -p 1?

The -p 1 has one worker: there's another thread which collates and prints answers. -p 1 is the default.

I suppose you mean "process", not thread? Still, I don't see the point of --serial.

The main point of --serial is that it allows you to debug problems in the doctesting framework without worrying about multiprocessing. :-)

I'm fine making it less prominent (having it not show up in the help display for sage -t for example, and not using it for --verbose mode). But I think it should stick around since it currently exists, and it makes some kinds of bugs much easier to track down.

I'm also using it for --gdb since it makes the tracebacks simpler, though I'm not sure that's necessary.

Do you ever use sage -t with valgrind? I'm not sure exactly what's wrong with sage -t --valgrind <FILENAME>.

[roed]

Replying to jdemeyer:

Replying to roed:

Sure, and for reporting what happened to the user this is fine. But from the child process' perspective, an unexpected KeyboardInterrupt has been raised and it should stop testing that file.

Okay, I see what you mean. I would propose not to special-case KeyboardInterrupt at all in the child process. When the parent process gets a KeyboardInterrupt, kill all child processes (without showing their output) and exit.

(note: since the old doctesting framework didn't do this either, I don't consider this a prerequisite for positive review, but a nice feature to have.)

I just tried changing the interrupt handling so that KeyboardInterrupt is handled in the parent process and it doesn't work as well: there's extraneous printing happening when the doctest framework thinks it's just printing an unexpected exception, and I don't see a good way to get rid of it.

I think the current handling of KeyboardInterrupts? is fine.

[roed]

I'm going to be offline until Tuesday. More feedback while I'm gone would be great. :-)

[jhpalmieri]

As far as I understand it, this new framework should allow for the same commands (e.g., sage -tp 6 --long devel/sage/sage/matrix/). In addition, though, there are new command-line options to sage-runtest, which should available through sage -t ..., right? Which of these new options should be documented in the help messages usage and/or usage_advanced at the top of spkg/bin/sage? Which should be documented in the developer's guide?

[roed]

I'm back, and I've been working on a patch to the developer's guide. I'll post something soon, and more comments on which options will be shown in usage.

[jdemeyer]

I'm going to build and test Sage again with these patches. Stay tuned...

[jdemeyer]

Needs to be rebased to #11871.

[roed]

Replying to jdemeyer:

Needs to be rebased to #11871.

Done. I will make sure the suggestions in comment 56 are addressed.

[roed]

The change to 12415_script.patch fixes a problem with interrupting doctests on sage.math.

[jdemeyer]

When doing make ptest and make ptestlong, all doctests are run but there is no summary at the end. The processes end with exit code 132 (which usually means an Illegal Instruction but probably not here).

The following are the last lines output by make ptest and make ptestlong:

sage -t devel/sage/doc/en/thematic_tutorials/lie/weyl_groups.rst
    [44 tests, 4.6 s]
sage -t devel/sage/doc/fr/tutorial/tour_plotting.rst
    [35 tests, 9.2 s]
sage -t devel/sage/doc/de/tutorial/tour_plotting.rst
    [51 tests, 10.7 s]
sage -t devel/sage/doc/en/tutorial/tour_plotting.rst
    [51 tests, 10.9 s]
sage -t devel/sage/doc/ru/tutorial/tour_plotting.rst
    [46 tests, 10.9 s]

and

sage -t --long devel/sage/sage/combinat/crystals/__init__.py
    [0 tests, 0.0 s]
sage -t --long devel/sage/sage/gsl/callback.pyx
    [0 tests, 0.0 s]
sage -t --long devel/sage/sage/ext/python_module.pxi
    [0 tests, 0.0 s]
sage -t --long devel/sage/sage/groups/perm_gps/all.py
    [0 tests, 0.0 s]
sage -t --long devel/sage/doc/en/bordeaux_2008/modular_forms_and_hecke_operators.rst
    [0 tests, 0.0 s]

[jdemeyer]

Then I get the following make ptestlong failures:

Running doctests with ID 2012-07-08-23-57-28-0d45df42.
Doctesting the Sage notebook.
Sorting sources by runtime so that slower doctests are run first....
Doctesting 2067 files using 6 threads.
Usage: sage -docbuild [OPTIONS] DOCUMENT (FORMAT | COMMAND)

sage-runtests: error: no such option: -p
sage -t --long devel/sage/doc/common/builder.py
    Bad exit: 2
********************************************************************************
Tests run before process failed:

********************************************************************************
sage -t --long devel/sage/sage/tests/interrupt.pyx
    [80 tests, 15.0 s]

sage -t --long devel/sage/sage/matrix/matrix2.pyx
    [1980 tests, 24.9 s]
**********************************************************************
File "devel/sage/sage/tests/cmdline.py", line 272, in sage.tests.cmdline.test_executable
Failed example:
    out.find("All tests passed!") >= 0
Expected:
    True
Got:
    False
**********************************************************************
File "devel/sage/sage/tests/cmdline.py", line 277, in sage.tests.cmdline.test_executable
Failed example:
    out.find("All tests passed!") >= 0
Expected:
    True
Got:
    False
**********************************************************************
1 items had failures:
   2 of 185 in sage.tests.cmdline.test_executable
***Test Failed*** 2 failures.
sage -t --long devel/sage/sage/tests/cmdline.py
    [184 tests, 23.0 s]

**********************************************************************
File "devel/sage/sage/doctest/control.py", line 263, in sage.doctest.control.DocTestController.add_files
Failed example:
    DC = DocTestController(DD, [])
Exception raised:
    Traceback (most recent call last):
      File "/release/merger/sage-5.1.rc0-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 590, in _run
        self.execute(example, compiled, test.globs)
      File "/release/merger/sage-5.1.rc0-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 881, in execute
        exec compiled in globs
      File "<doctest sage.doctest.control.DocTestController.add_files[2]>", line 1, in <module>
        DC = DocTestController(DD, [])
      File "/release/merger/sage-5.1.rc0-12415/local/lib/python2.7/site-packages/sage/doctest/control.py", line 142, in __init__
        print "Unable to open logfile at %s\nProceeding without logging."%(self.logfile)
    AttributeError: 'DocTestController' object has no attribute 'logfile'
**********************************************************************

+ errors related to #13145.

[roed]

I thought I'd solved the sporadic problem in sage.tests.interrupt by increasing the delays in test_sig_block_outside_sig_on: after the change I ran sage -tp --sagenb --long devel/sage/doc/common devel/sage/doc/[a-z][a-z] devel/sage/sage 10 times with no failures (where before there had been 5 failures in interrupt.pyx). But I just got another one. Maybe it has to do with the load on sage.math? There are more processes running now than when I ran the test earlier.

Jeroen, would you be willing to take a look at it since you wrote the tests in that file?

All the other tests pass for me, with the exception of startup.py.

[jdemeyer]

Rebased the scripts patch to sage-5.1.

[jdemeyer]

The sagenb patch doesn't apply to the new notebook (#11080).

[jdemeyer]

Replying to roed:

I thought I'd solved the sporadic problem in sage.tests.interrupt by increasing the delays in test_sig_block_outside_sig_on

The tests should be designed in such a way that they work regardless of the delay.

[roed]

Replying to jdemeyer:

Replying to roed:

I thought I'd solved the sporadic problem in sage.tests.interrupt by increasing the delays in test_sig_block_outside_sig_on

The tests should be designed in such a way that they work regardless of the delay.

Agreed, but I'm at a loss for what's causing the problem, and it's difficult to debug since it's sporadic and a segfault.

[jdemeyer]

I have added some changes to local/bin/.hgignore to the scripts patch. I discovered there was a problem when I put the file sage-runtests in local/bin without adding it using hg. Surprisingly, hg status didn't show sage-runtests.

[roed]

I updated the sagenb patch

[kini]

I imported the patch: ​https://github.com/sagemath/sagenb/pull/84

I'll cut a sagenb 0.10.2 release with this fix in it (and put it on #13121). Jeroen, are you aware of any other tickets with bugfix-type patches to sagenb which I could merge at the same time?

[kini]

Actually, since this doctest fix actually breaks doctests with the current doctesting framework, should I leave this patch for sagenb 0.11 or something? How close would you say this ticket is to positive review? I notice it's set to milestone 5.3, whereas I'm hoping that #13121 can get into 5.2, so maybe that is the way to go.

[jdemeyer]

Replying to kini:

Actually, since this doctest fix actually breaks doctests with the current doctesting framework, should I leave this patch for sagenb 0.11 or something?

Yes please.

How close would you say this ticket is to positive review?

I think it's mostly finished, but since this is a big change, I'm certainly not merging it in sage-5.2. Also, there is a good chance that various small issues will come up here.

I notice it's set to milestone 5.3, whereas I'm hoping that #13121 can get into 5.2, so maybe that is the way to go.

Yes.

[jdemeyer]

Just one failure remaining related to this ticket:

**********************************************************************
File "devel/sage/sage/doctest/control.py", line 258, in sage.doctest.control.DocTestController.add_files
Failed example:
    DC = DocTestController(DD, [])
Expected nothing
Got:
    Unable to open logfile at /release/merger/sage-5.1-12415/home/.sage//tmp/test.log
    Proceeding without logging.
sage -t devel/sage/sage/ext/gmp.pxi
    [0 tests, 0.0 s]
**********************************************************************
1 items had failures:
   1 of  15 in sage.doctest.control.DocTestController.add_files
***Test Failed*** 1 failures.
sage -t devel/sage/sage/doctest/control.py
    [115 tests, 3.6 s]

But also the formatting of the above failure looks strange:

1) Why does

sage -t devel/sage/sage/ext/gmp.pxi
    [0 tests, 0.0 s]

appear in the middle of the failure?

2) Could you format the output as

sage -t devel/sage/sage/doctest/control.py
**********************************************************************
[...failure...]
**********************************************************************
1 items had failures:
   1 of  15 in sage.doctest.control.DocTestController.add_files
***Test Failed*** 1 failures.
    [115 tests, 3.6 s]

I would even shorten the last two lines to

    [115 tests, 1 failed, 3.6 s]

And I would add a function like

def count_noun(number, noun):
    if number == 1:
        return "1 %s"%noun
    else:
        return "%d %ss"%(number,noun)

So you can do

print count_noun(n, 'item'), "had failures"

[jdemeyer]

The KeyboardInterrupt example ​http://boxen.math.washington.edu/home/jdemeyer/doctest/keyboardinterrupt.py still doesn't work correctly:

Running doctests with ID 2012-07-13-10-53-02-ed232e22.
Doctesting 1 file.
sage -t /home/jdemeyer/doctest/keyboardinterrupt.py
    Unexpected KeyboardInterrupt raised in file
********************************************************************************
Tests run before interrupt:
sage: raise KeyboardInterrupt ## line 2 ##

********************************************************************************
------------------------------------------------------------------------
sage -t /home/jdemeyer/doctest/keyboardinterrupt.py # Unhandled KeyboardInterrupt
------------------------------------------------------------------------
Total time for all tests: 1.1 seconds
    cpu time: 0.0 seconds
    cumulative wall time: 0.0 seconds

The expected result is that the test passes. I don't mind if you don't fix this (currently, it's also broken), but I thought you should know...

[jdemeyer]

Concerning the logfile error: I think you are making the mistaken assumption that $SAGE_TESTDIR is an existing directory. But I also find it strange that a doctest writes to a logfile inside SAGE_TESTDIR, I don't really like that.

[jdemeyer]

When testing sage/tests/interrupt.pyx verbosely, I regularly get errors of the form

[...]
Trying (line 637):    test_try_finally_signal()
Expecting:
    Traceback (most recent call last):
    ...
    RuntimeError: Aborted
ok [0.23s]
Trying (line 100631):    sig_on_count()
Expecting:
    0
ok [0.00s]
sage -t --long devel/sage/sage/tests/interrupt.pyx
Traceback (most recent call last):
  File "/release/merger/sage-5.1-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 1634, in __call__
  File "/release/merger/sage-5.1-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 725, in run
  File "/release/merger/sage-5.1-12415/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 556, in _run
AttributeError: Example instance has no attribute 'options'

------------------------------------------------------------------------
sage -t --long devel/sage/sage/tests/interrupt.pyx # AttributeError in loading
------------------------------------------------------------------------
Total time for all tests: 12.7 seconds
    cpu time: 0.0 seconds
    cumulative wall time: 0.0 seconds

This looks like a bug in the doctesting framework (unless somehow the interrupt tests corrupt the doctest process?)

[roed]

Replying to jdemeyer:

The KeyboardInterrupt example ​http://boxen.math.washington.edu/home/jdemeyer/doctest/keyboardinterrupt.py still doesn't work correctly:

Running doctests with ID 2012-07-13-10-53-02-ed232e22.
Doctesting 1 file.
sage -t /home/jdemeyer/doctest/keyboardinterrupt.py
    Unexpected KeyboardInterrupt raised in file
********************************************************************************
Tests run before interrupt:
sage: raise KeyboardInterrupt ## line 2 ##

********************************************************************************
------------------------------------------------------------------------
sage -t /home/jdemeyer/doctest/keyboardinterrupt.py # Unhandled KeyboardInterrupt
------------------------------------------------------------------------
Total time for all tests: 1.1 seconds
    cpu time: 0.0 seconds
    cumulative wall time: 0.0 seconds

The expected result is that the test passes. I don't mind if you don't fix this (currently, it's also broken), but I thought you should know...

That's because your expected output has an extra colon. If you delete the trailing colon it passes tests.

With the extra colon it's an unexpected KeyboardInterrupt.

[roed]

Replying to jdemeyer:

Just one failure remaining related to this ticket:

**********************************************************************
File "devel/sage/sage/doctest/control.py", line 258, in sage.doctest.control.DocTestController.add_files
Failed example:
    DC = DocTestController(DD, [])
Expected nothing
Got:
    Unable to open logfile at /release/merger/sage-5.1-12415/home/.sage//tmp/test.log
    Proceeding without logging.
sage -t devel/sage/sage/ext/gmp.pxi
    [0 tests, 0.0 s]
**********************************************************************
1 items had failures:
   1 of  15 in sage.doctest.control.DocTestController.add_files
***Test Failed*** 1 failures.
sage -t devel/sage/sage/doctest/control.py
    [115 tests, 3.6 s]

But also the formatting of the above failure looks strange:

1) Why does

sage -t devel/sage/sage/ext/gmp.pxi
    [0 tests, 0.0 s]

appear in the middle of the failure?

2) Could you format the output as

sage -t devel/sage/sage/doctest/control.py
**********************************************************************
[...failure...]
**********************************************************************
1 items had failures:
   1 of  15 in sage.doctest.control.DocTestController.add_files
***Test Failed*** 1 failures.
    [115 tests, 3.6 s]

I would even shorten the last two lines to

    [115 tests, 1 failed, 3.6 s]

And I would add a function like

def count_noun(number, noun):
    if number == 1:
        return "1 %s"%noun
    else:
        return "%d %ss"%(number,noun)

So you can do

print count_noun(n, 'item'), "had failures"

Cool. I will work on these.

I'm going to be mostly (or entirely) out of communication for the next few days. Hopefully I'll have some changes available on Monday.

[jhpalmieri]

From a discussion on ​sage-combinat-devel: would it be possible to optionally print extra information after doctesting: how many optional doctests were skipped, and perhaps how they were labeled? ("skipped 5 doctests marked "optional -- bug")

[roed]

Replying to jhpalmieri:

From a discussion on ​sage-combinat-devel: would it be possible to optionally print extra information after doctesting: how many optional doctests were skipped, and perhaps how they were labeled? ("skipped 5 doctests marked "optional -- bug")

Yeah, that shouldn't be a problem. But I'd like to put a feature freeze on this ticket and open a new ticket for it: I'm already regretting adding the new debugging feature since I'm struggling with debugging its interaction with KeyboardInterrupts.

I just opened #13278 for this.

[kini]

Ping - should this still be needs_work?

[jdemeyer]

There's still the interrupt.pyx failures which need to be investigated (probably by me since I know most about interrupts).

[roed]

If you could look at those it would be great. My computer is currently being repaired, but I can try to take another shot at this next week.

[roed]

Alright, I've rebased this against 5.4.rc1 and made the suggested changes in #13147. There's still an intermittent failure in sage.tests.interrupt and I'm at a loss for what's causing it. Help would be appreciated.

[roed]

I've put the output before segfault from a case where interrupt.pyx failed at ​http://pastebin.com/Yvs8Ev68 (expiring in 1 month).

[roed]

I've moved the debug functionality that triggers on an incorrect result to #13610 since I was struggling to get the interrupt handling working correctly (IPython embedded shells intercept KeyboardInterrupts). With this change the only work issue I'm aware of on this ticket is the intermittent failure in interrupt.pyx. Testing just interrupt.pyx doesn't trigger this failure (or at least does so rarely); run sage -t sage/tests/parigp.py sage/tests/interrupt.pyx for example.

[roed]

Ok, I found another issue which I'm not going to fix tonight. The code that parses a file and generates the tests has a bug somewhere that means some files with tests are not getting tested. I need to track down the bug and add some doctests to make sure this kind of thing doesn't happen again.

[roed]

Alright, I fixed a bunch of bugs in the parsing of files. I added two new patches since the old ones were getting big. Sorry for the huge size of this ticket: some of the changes in 12415_more_doctest_fixes.patch can be split off into new tickets, but many of them need to be made along with the switch to the new testing code.

[roed]

Here's my current status on the interrupt.pyx problem.

• It occurs only if interrupt.pyx is not the first file being tested (so sage -t rings/big_oh.py tests/interrupt.pyx will show it for example)
• The segfault is actually caused by the test at line 694 of interrupt.pyx: sage: test_sig_block()

I tried looking into the signal handling code but got lost. Any ideas?

[jdemeyer]

I can have a look at the interrupt code, but not now...

[roed]

Fair enough. Do you have any idea when you might have a chance? Or any suggestions for debugging it myself?

[jhpalmieri]

I have no idea what's going on, but to follow up on David's comment: on an OS X 10.8 machine, if I run sage -t rings/big_oh.py tests/interrupt.pyx, I get an error at line 744. If I make either of the following two changes, the error goes away:

sage/tests/interrupt.pyx

@@ -691 +691 @@
     TESTS::
 
         sage: from sage.tests.interrupt import *
-        sage: test_sig_block()
-        42
     """
     cdef volatile_int v = 0
 

or

sage/tests/interrupt.pyx

@@ -741 +741 @@
 
     TESTS::
 
-        sage: from sage.tests.interrupt import *
-        sage: for i in range(4):  # Several times to reduce chances of false positive
-        ...       test_signal_during_malloc()
     """
     signal_after_delay(SIGINT, delay)
     try:

For the second one, I still get the error if I keep line 744,

sage: from sage.tests.interrupt import *

but remove the actual doctest. Does this have any significance for anyone?

[roed]

The problem seems to be caused by

sage: test_sig_block()
42

but it only shows up if enough time is taken up by later tests. So you can delete

sage: from sage.tests.interrupt import *
sage: for i in range(4):  # Several times to reduce chances of false positive
...       test_signal_during_malloc()

and add something else, and you still get the error.

[roed]

By commenting out most of the tests in that file, I can get the following error message:

Fatal Python error: GC object already tracked

I still get a SIGABRT, but now the bad exit code is -6 rather than -11.

[roed]

Alright. I have a minimal example that doesn't rely on the doctesting framework. Of course, I still don't know how to resolve the issue, but at least it should be easier to work on. See #13748.

[jhpalmieri]

If the issue isn't related to the new doctesting framework, but is a pre-existing condition revealed by it, then it shouldn't be a dependency, but a separate issue. If that was the only issue with this ticket, then this ticket could be merged, right?

[roed]

Replying to jhpalmieri:

If the issue isn't related to the new doctesting framework, but is a pre-existing condition revealed by it, then it shouldn't be a dependency, but a separate issue. If that was the only issue with this ticket, then this ticket could be merged, right?

I have no problem with that interpretation. But in some sense it is related to the new doctesting framework since we weren't using Python's multiprocessing module before.

So, does anyone want to give this ticket a positive review?

[jdemeyer]

Rebased and merged the two doctest patches.

[jdemeyer]

Merged the two framework patches, removed the change to sage/tests/interrupt.pyx

[jdemeyer]

I still don't like the DocTestWorker.annihilate() method which parses ps output to figure out which processes to kill.

[roed]

Robert wrote that code. :-) I think the issue is that some doctests may spawn new processes that can survive their death. Do you have an alternate approach to suggest?

I'm very happy that you found the problem in #13748; I will try to take a look at this while I'm at the Joint meetings next week. In general I have very little time this month....

[jdemeyer]

There are various new doctest errors, all of them look easy to fix. But also two errors in the doctest framework itself:

sage -t --long devel/sage/sage/doctest/sources.py
**********************************************************************
File "devel/sage/sage/doctest/sources.py", line 177, in sage.doctest.sources.DocTestSource._process_doc
Failed example:
    doctests == manual_doctests
Expected:
    True
Got:
    False
**********************************************************************
File "devel/sage/sage/doctest/sources.py", line 655, in sage.doctest.sources.FileDocTestSource._test_enough_doctests
Failed example:
    for path, dirs, files in itertools.chain(os.walk(sage_loc), os.walk(doc_loc)): # long time
        path = os.path.relpath(path)
        for F in files:
            _, ext = os.path.splitext(F)
            if ext in ('.py', '.pyx', '.sage', '.spyx', '.rst', '.tex'):
                filename = os.path.join(path, F)
                FDS = FileDocTestSource(filename, True, True, True, False)
                FDS._test_enough_doctests(verbose=False)
Expected:
    There are 3 unexpected tests being run in .../sage/doctest/parsing.py
    There are 1 tests in .../sage/ext/c_lib.pyx that are not being run
    There are 2 tests in .../sage/server/notebook/worksheet.py that are not being run
    There are 5 tests in .../doc/en/tutorial/interfaces.rst that are not being run
Got:
    There are 2 tests in devel/sage/sage/server/notebook/worksheet.py that are not being run
    There are 2 unexpected tests being run in devel/sage/sage/misc/cython.py
    There are 1 tests in devel/sage/sage/ext/c_lib.pyx that are not being run
    There are 3 unexpected tests being run in devel/sage/sage/doctest/parsing.py
    There are 5 tests in devel/sage/doc/en/tutorial/interfaces.rst that are not being run
    There are 1130 tests in devel/sage/doc/output/latex/en/reference/reference.tex that are not being run
    There are 51 tests in devel/sage/doc/output/latex/en/tutorial/SageTutorial.tex that are not being run
    There are 4 tests in devel/sage/doc/output/latex/en/thematic_tutorials/thematic_tutorials.tex that are not being run
    There are 6 tests in devel/sage/doc/output/latex/en/prep/prep_tutorials.tex that are not being run
    There are 2 tests in devel/sage/doc/output/latex/en/numerical_sage/numerical_sage.tex that are not being run
    There are 15 tests in devel/sage/doc/output/latex/en/developer/developer.tex that are not being run
    There are 16 tests in devel/sage/doc/output/latex/en/constructions/constructions.tex that are not being run
    There are 51 tests in devel/sage/doc/output/latex/ru/tutorial/SageTutorial_ru.tex that are not being run
    There are 51 tests in devel/sage/doc/output/latex/fr/tutorial/tutorial-fr.tex that are not being run
    There are 51 tests in devel/sage/doc/output/latex/de/tutorial/SageTutorial-de.tex that are not being run
**********************************************************************

Also, the directory devel/sagenb/sagenb/data should probably not be tested, as there are failures because of TAB characters in the MathJax rst documentation.

[jdemeyer]

Do you guys consider it a feature or a bug that

"""
sage: 1e16     # relative tol 1e-10
10^16
"""

doesn't work? See #12815.

[jdemeyer]

What I'm missing in this patchbomb is a high-level overview of how everything works. To me, it looks like a large lump of code (which seems to work pretty well) which is hard to understand.

[jdemeyer]

Typo:

Comparison ist just comparison of the underlying lists.

[jdemeyer]

Replying to roed:

Robert wrote that code. :-) I think the issue is that some doctests may spawn new processes that can survive their death. Do you have an alternate approach to suggest?

There is some commented-out code mentioning process groups, it would be a good idea to make that work.

But I'm also a bit lost on how the fork()ing actually works and how many Sage sessions are involved.

[roed]

Replying to jdemeyer:

What I'm missing in this patchbomb is a high-level overview of how everything works. To me, it looks like a large lump of code (which seems to work pretty well) which is hard to understand.

I will add somw top level documentation next week.

[jdemeyer]

#13908 might also help with proper killing.

[robertwb]

Replying to jdemeyer:

Do you guys consider it a feature or a bug that

"""
sage: 1e16     # relative tol 1e-10
10^16
"""

doesn't work? See #12815.

Feature. See new comment on that ticket.

[fbissey]

Looks like I have to depend on this for the numpy-1.7 upgrade at #11334, so I am tagging along :)

[fbissey]

It is interesting. With each new version of numpy we seem to have new instances of

Warning: divide by zero encountered in divide

appearing in doctests. This suggest that numpy sometimes mixes stderr and stdout or that they are very intent to tell you about these warnings. All the instances of this warning that are fixed in 12415_stderr_vs_51b5.patch also appears with the upgrade to numpy 1.7.0 - plus some more.

[jdemeyer]

Combined 12415_stderr_vs_51b5.patch and 12415_doctest_fixes.patch​ and rebased.

12415_framework.patch​ needs to be rebased but displayhook.py changed substantially in #12719, so I don't know what to do.

[jdemeyer]

Apply to root repository

[jdemeyer]

Patch to script repo; now removes old files

[jdemeyer]

Is this because of the displayhook?

File "devel/sage/sage/combinat/cluster_algebra_quiver/quiver.py", line 996, in sage.combinat.cluster_algebra_quiver.quiver.ClusterQuiver.mutation_sequence
Failed example:
    [T.b_matrix() for T in seq]
Expected:
    [
    [ 0  1  0  0]  [ 0 -1  0  0]  [ 0  1 -1  0]
    [-1  0 -1  0]  [ 1  0 -1  0]  [-1  0  1  0]
    [ 0  1  0  1]  [ 0  1  0  1]  [ 1 -1  0  1]
    [ 0  0 -1  0], [ 0  0 -1  0], [ 0  0 -1  0]
    ]
Got:
    [[ 0  1  0  0]
    [-1  0 -1  0]
    [ 0  1  0  1]
    [ 0  0 -1  0], [ 0 -1  0  0]
    [ 1  0 -1  0]
    [ 0  1  0  1]
    [ 0  0 -1  0], [ 0  1 -1  0]
    [-1  0  1  0]
    [ 1 -1  0  1]
    [ 0  0 -1  0]]

[roed]

Replying to jdemeyer:

Is this because of the displayhook?

File "devel/sage/sage/combinat/cluster_algebra_quiver/quiver.py", line 996, in sage.combinat.cluster_algebra_quiver.quiver.ClusterQuiver.mutation_sequence
Failed example:
    [T.b_matrix() for T in seq]
Expected:
    [
    [ 0  1  0  0]  [ 0 -1  0  0]  [ 0  1 -1  0]
    [-1  0 -1  0]  [ 1  0 -1  0]  [-1  0  1  0]
    [ 0  1  0  1]  [ 0  1  0  1]  [ 1 -1  0  1]
    [ 0  0 -1  0], [ 0  0 -1  0], [ 0  0 -1  0]
    ]
Got:
    [[ 0  1  0  0]
    [-1  0 -1  0]
    [ 0  1  0  1]
    [ 0  0 -1  0], [ 0 -1  0  0]
    [ 1  0 -1  0]
    [ 0  1  0  1]
    [ 0  0 -1  0], [ 0  1 -1  0]
    [-1  0  1  0]
    [ 1 -1  0  1]
    [ 0  0 -1  0]]

Yeah, that's the kind of error that would occur because of displayhook. I'll take a look.

[jdemeyer]

All other files (except 12415_framework.patch​) have been rebased to sage-5.7.beta1.

[roed]

Great. I'm building a copy of sage-5.7.beta1 now and will try to rebase 12415_framework.patch​ to it later today.

[jdemeyer]

Replying to roed:

Great. I'm building a copy of sage-5.7.beta1 now and will try to rebase 12415_framework.patch​ to it later today.

That would be great!

I would really like to finish this ticket. I feel that we're almost there, the main thing I would like to change is the handling of subprocesses (including but not limited to killing).

[roed]

The new doctesting code

[roed]

I think I've fixed the display hook problem. I just ran make ptestlong and found some errors; I'm looking into them and will report back.

I'm working on some general documentation, but some help on the annihilate method would be useful, since I know nothing about process control groups.

[jdemeyer]

There are still doctest failures in the doctest framework, see comment 140.

[jdemeyer]

More doctest framework doctest failures:

sage -t --long devel/sage/sage/doctest/control.py
**********************************************************************
File "devel/sage/sage/doctest/control.py", line 566, in sage.doctest.control.DocTestController.cleanup
Failed example:
    DC.run()
Exception raised:
    Traceback (most recent call last):
      File "/release/sage-5.7.beta3-doctest/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 595, in _run
        self.execute(example, compiled, test.globs)
      File "/release/sage-5.7.beta3-doctest/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 980, in execute
        exec compiled in globs
      File "<doctest sage.doctest.control.DocTestController.cleanup[8]>", line 1, in <module>
        DC.run()
      File "/release/sage-5.7.beta3-doctest/local/lib/python2.7/site-packages/sage/doctest/control.py", line 725, in run
        self.test_safe_directory()
      File "/release/sage-5.7.beta3-doctest/local/lib/python2.7/site-packages/sage/doctest/control.py", line 270, in test_safe_directory
        .format(os.getcwd()))
    RuntimeError: refusing to run doctests from the current directory '/home/jdemeyer/.sage/temp/sage.math.washington.edu/10273/dir_2B_1k4/test' since untrusted users could put files in this directory, making it unsafe to run Sage code from
**********************************************************************

Then there is a bunch of

/release/sage-5.7.beta3-doctest/local/lib/python2.7/site-packages/Cython/Build/Dependencies.py:229: UnicodeWarning: Unicode equal comparis
on failed to convert both arguments to Unicode - interpreting them as being unequal
  if code[q-1] == u'\\':

in between the tests, for example:

sage -t --long devel/sage/sage/combinat/species/empty_species.py
    [38 tests, 0.1 s]
sage -t --long devel/sage/sage/combinat/sf/kfpoly.py
    [60 tests, 0.1 s]
sage -t --long devel/sage/sage/combinat/words/shuffle_product.py
    [63 tests, 0.1 s]
/release/sage-5.7.beta3-doctest/local/lib/python2.7/site-packages/Cython/Build/Dependencies.py:229: UnicodeWarning: Unicode equal comparis
on failed to convert both arguments to Unicode - interpreting them as being unequal
  if code[q-1] == u'\\':
sage -t --long devel/sage/sage/categories/algebra_modules.py
    [9 tests, 0.1 s]
sage -t --long devel/sage/sage/numerical/backends/ppl_backend.pyx
    [167 tests, 0.1 s]
sage -t --long devel/sagenb-main/sagenb/misc/misc.py
    [36 tests, 0.0 s]

[jdemeyer]

Quick question: how many DocTestWorker instances are created? Just one? Or N if we set MAKE=make -jN?

[jdemeyer]

There is a lot of

if output_semaphore is not None:
    output_semaphore.acquire()

in the code which could be simplified assuming that output_semaphore is never None. Could we ensure that?

In fact, the whole block

try:
    if output_semaphore is not None:
        output_semaphore.acquire()
    do_something()
finally:
    if output_semaphore is not None:
        output_semaphore.release()

could be simplified to

with output_semaphore:
    do_something()

[jdemeyer]

Replying to roed:

The main point of --serial is that it allows you to debug problems in the doctesting framework without worrying about multiprocessing. :-)

I vote to completely remove the --serial option since for me the only effect is that it makes the code more complicated. Consider for example:

        except KeyboardInterrupt:
            if result_pipe is None:
                # We're in serial mode
                raise
            # Otherwise, we've been started by a worker: we'll return the result in the finally block
            result = 0, DictAsObject(dict(err='ctlC')), ""
[...]
        finally:
            if result_pipe is None:
                return result
            else:
                result_pipe.put(result, False)

If I want to fix KeyboardInterrupts in doctests, I now have to think about two code paths instead of one.

[jdemeyer]

Any clue where this failure comes from?

sage -t --long devel/sagenb-main/sagenb/notebook/worksheet.py
**********************************************************************
File "devel/sagenb-main/sagenb/notebook/worksheet.py", line 197, in sagenb.notebook.worksheet.Worksheet.?
Failed example:
    sagenb.notebook.misc.notebook = nb
Exception raised:
    Traceback (most recent call last):
      File "/release/sage-5.7.beta3-doctest/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 595, in _run
        self.execute(example, compiled, test.globs)
      File "/release/sage-5.7.beta3-doctest/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 980, in execute
        exec compiled in globs
      File "<doctest sagenb.notebook.worksheet.Worksheet.?[2]>", line 1, in <module>
        sagenb.notebook.misc.notebook = nb
    AttributeError: 'module' object has no attribute 'misc'
**********************************************************************

[jdemeyer]

Answering my own question, it seems that N DocTestWorkers are started with make -j N.

But I don't understand the design choice of having two levels of multiprocessing: one from the master process to the DocTestWorker and one from the DocTestWorker to the DocTestTask.

I surely need to think more about this, but I propose a redesign with only one level of multiprocessing, completely bypassing the DocTestWorker class. This would give the benefits of "serial" processing while still allowing parallel doctests.

[jdemeyer]

I would love to cooperate on this ticket, but I'm having a really hard time to understand everything. As I said before, this absolutely needs some high-level documentation explaining the various classes involved and their inter-relations (in particular, the classes in forker.py).

[roed]

Replying to jdemeyer:

I would love to cooperate on this ticket, but I'm having a really hard time to understand everything. As I said before, this absolutely needs some high-level documentation explaining the various classes involved and their inter-relations (in particular, the classes in forker.py).

Hi Jeroen, Sorry for the slow response time: I've had a visitor here in Calgary who's leaving this evening. I've started writing up overall documentation, and will work on it tonight.

In answer to your question about two layers of multiprocessing, the reason is to insulate the controlling process from segfaults and serious failures in the files being tested. If we come up with a design that satisfies that goal and also allows testing with multiple processes through sage -t -p N I'm happy to change things. I certainly wouldn't call myself an expert on writing multi-process code.

I'll write more this evening, and also review #14079 and #14080.

[jdemeyer]

Replying to roed:

In answer to your question about two layers of multiprocessing, the reason is to insulate the controlling process from segfaults and serious failures in the files being tested. If we come up with a design that satisfies that goal and also allows testing with multiple processes through sage -t -p N I'm happy to change things.

We obviously need one level of multiprocessing to allow segmentation faults. But my idea would be to skip the first level of multiprocessing and move the code which is currently in DocTestWorker to the top-level process. I think that would simplify the code substantially.

[roed]

Replying to jdemeyer:

Replying to roed:

In answer to your question about two layers of multiprocessing, the reason is to insulate the controlling process from segfaults and serious failures in the files being tested. If we come up with a design that satisfies that goal and also allows testing with multiple processes through sage -t -p N I'm happy to change things.

We obviously need one level of multiprocessing to allow segmentation faults. But my idea would be to skip the first level of multiprocessing and move the code which is currently in DocTestWorker to the top-level process. I think that would simplify the code substantially.

How would you run multiple files in parallel then?

[jdemeyer]

Replying to roed:

How would you run multiple files in parallel then?

Like I said. Have one master process doing the jobs of the current master process + the current DocTestWorker. That master process would start child processes for every file to be doctested, check for timeouts and crashes of the child processes.

And use #14079 to manage everything without busy-waiting.

[roed]

Okay. I have no objections to removing the -serial option and changing the process management as you suggest. It sounds like you have a good idea of how to rewrite it; how can I be useful? I can certainly review #14080 and #14079 and add overall documentation. What else would be useful?

[jdemeyer]

Replying to roed:

how can I be useful?

There are still some doctest failures left. I fixed a few in my reviewer patch (and #14070) but there are some I couldn't immediately fix. There is also the issue with TAB characters in devel/sagenb/sagenb/data, ideally that directory would be skipped from doctesting.

But try not to change forker.py too much, as I'm thinking of substantial changes there.

[roed]

Replying to jdemeyer:

Replying to roed:

how can I be useful?

There are still some doctest failures left. I fixed a few in my reviewer patch (and #14070) but there are some I couldn't immediately fix. There is also the issue with TAB characters in devel/sagenb/sagenb/data, ideally that directory would be skipped from doctesting.

But try not to change forker.py too much, as I'm thinking of substantial changes there.

Sounds good. I'll work on fixing doctest failures.

[jdemeyer]

I also don't like this:

        except IOError:
            # File doesn't exist
            result = 0, DictAsObject(dict(err='file')), ""

You assume that any IOError comes from the fact that the doctested file doesn't exist. But it could also be a problem instead with the temporary file used for output (no space on /tmp for example). Then the error message "File not found" would be very confusing. I think we need to explicitly check the existence of the doctested file and not handle IOError specially.

[jdemeyer]

In "normal" mode (non-verbose, non-debug, non-serial), does the DocTestTask or DocTestRunner ever print something to the real (unspoofed) stdout/stderr?

[roed]

Replying to jdemeyer:

In "normal" mode (non-verbose, non-debug, non-serial), does the DocTestTask or DocTestRunner ever print something to the real (unspoofed) stdout/stderr?

I don't think so.

[roed]

Replying to jdemeyer:

I also don't like this:

        except IOError:
            # File doesn't exist
            result = 0, DictAsObject(dict(err='file')), ""

You assume that any IOError comes from the fact that the doctested file doesn't exist. But it could also be a problem instead with the temporary file used for output (no space on /tmp for example). Then the error message "File not found" would be very confusing. I think we need to explicitly check the existence of the doctested file and not handle IOError specially.

Fair enough.

[jdemeyer]

I think the word "output" is badly overused (there is the standard output, the file output=os.tmpfile(), the string output referring to the contents of the output file and delayed_output).

I propose to rename:

• delayed_output to messages
• output (the file) to outtmpfile (or tmpoutfile?)

And am I right that delayed_output is empty in normal mode when there are no doctest failures?

[roed]

Replying to jdemeyer:

Can I replace "delayed_output" by "messages" because I think the word "output" is overused (there is the standard output, the file outfile=os.tmpfile() and delayed_output).

And am I right that delayed_output is empty in normal mode when there are no doctest failures?

Sure, either "messages" or "delayed_messages" is fine. It should be empty in normal mode with no failures.

[jdemeyer]

Edited 181 because I noticed there is output the file and output the contents of the file.

[roed]

Replying to jdemeyer:

I think the word "output" is badly overused (there is the standard output, the file output=os.tmpfile(), the string output referring to the contents of the output file and delayed_output).

I propose to rename:

• delayed_output to messages
• output (the file) to outtmpfile (or tmpoutfile?)

I like outtmpfile.

[jdemeyer]

First version of my updated doctesting framework.

[roed]

Replying to jdemeyer:

First version of my updated doctesting framework.

Some comments:

• For compatibility with Python's doctest module, summarize should take verbose as the first argument and msgfile as an optional second argument.
• It's sage.ext.pselecter rather than `sage.ext.pselect, unless you changed #14079.
• Currently I get a timeout whenever I run tests on a file.
• Why did you disable the code that sets following in _parallel_dispatch?

Overall, I think the changes are good ones.

[jdemeyer]

Replying to roed:

• For compatibility with Python's doctest module, summarize should take verbose as the first argument and msgfile as an optional second argument.

Fair enough. I never considered this compatibility, so it is quite possible that I introduced more incompatibilities.

• It's sage.ext.pselecter rather than `sage.ext.pselect, unless you changed #14079.

Yes, I did change #14079 but didn't realise that I hadn't uploaded the new patch. Anyway, I am looking into the problem on OS X.

• Currently I get a timeout whenever I run tests on a file.

Could be the same OS-dependent problem as the one you reported in #14079.

• Why did you disable the code that sets following in _parallel_dispatch?

Simply because it is work in progress, new tests are needed. My DocTestWorker has a substantially different function from the old DocTestWorker, so I cannot recycle the tests.

[jdemeyer]

Updated patch (I haven't looked at the OS X specific issue).

[jdemeyer]

I noticed a change in behaviour and I'm wondering whether it is intentional.

Old doctesting framework outputs like:

sage -t file.py
<messages>
         [4.1 s]

New doctesting framework outputs like:

<messages>
sage -t file.py
    [1 test, 1 failure, 1.7 s]

I dislike the last way of outputting, especially in --verbose mode, because there is no mention of what file is being tested. You see:

Running doctests with ID 2013-02-13-12-55-39-de348564.
Doctesting 1 file.
Trying (line 2):    cython('sig_on()')
Expecting nothing
ok [1.61 s]
...

"line 2" of which file?...

[roed]

Replying to jdemeyer:

I noticed a change in behaviour and I'm wondering whether it is intentional.

Old doctesting framework outputs like:

sage -t file.py
<messages>
         [4.1 s]

New doctesting framework outputs like:

<messages>
sage -t file.py
    [1 test, 1 failure, 1.7 s]

I dislike the last way of outputting, especially in --verbose mode, because there is no mention of what file is being tested. You see:

Running doctests with ID 2013-02-13-12-55-39-de348564.
Doctesting 1 file.
Trying (line 2):    cython('sig_on()')
Expecting nothing
ok [1.61 s]
...

"line 2" of which file?...

Adding the number of tests and number of failures was intentional (to which I assume you don't object). The change in order is an artifact of the code that delayed printing. When there are lots of processes running parallel, you can't output

sage -t file.py

before starting testing, since the messages will get mixed up. I agree that the line describing which file is being tested should come at the beginning.

[jdemeyer]

Replying to roed:

I agree that the line describing which file is being tested should come at the beginning.

OK, so you agree with

sage -t file.py
<messages>
    [1 test, 1 failure, 1.7 s]

I would move the part of report() which prints the "sage -t ..." header to a new function report_start() (for example) and then correct the logic in forker.py to call that function at the appropriate time. Does that sound good?

[roed]

Replying to jdemeyer:

Replying to roed:

I agree that the line describing which file is being tested should come at the beginning.

OK, so you agree with

sage -t file.py
<messages>
    [1 test, 1 failure, 1.7 s]

I would move the part of report() which prints the "sage -t ..." header to a new function report_start() (for example) and then correct the logic in forker.py to call that function at the appropriate time. Does that sound good?

Sounds good. Presumably it will get printed to the msgfile before all of the other messages and then actually printed to the screen in whatever way is appropriate.

[jdemeyer]

Could you please review 12415_doctest_review.patch​? It contains all my reviewer changes for doctests in the Sage library (i.e. all changes not for the doctest framework).

[roed]

Replying to jdemeyer:

Could you please review 12415_doctest_review.patch​? It contains all my reviewer changes for doctests in the Sage library (i.e. all changes not for the doctest framework).

I'm running tests on OS X 10.6.8 with sage 5.7.beta1.

• Your changes to sage.calculus.test_sympy break doctests on my machine: they were correct before the change. Presumably these results are system dependent and should be changed somehow.
• I get a bad exit in sage.misc.interpreter at line 132 (in get_test_shell()): it prints out a bunch of help text from IPython, ending with

  [SageTerminalApp] Bad config encountered during initialization:
  [SageTerminalApp] Unrecognized flag: '--all'
  

I'm not really sure what's happening here: perhaps it's related to the IPython upgrade?

• The same thing happens in sage.misc.sage_extension at line 22.
• There's still an error in sagenb.notebook.worksheet line 196: sagenb.notebook has no attribute misc. I've seen this before and it should be easy to fix.
• There are problems running some tests in sage.doctest.control that may go away with your new code. If not I have fixes for them.

How is 12415_review.patch​ coming along?

[jdemeyer]

Replying to roed:

Replying to jdemeyer:

Could you please review 12415_doctest_review.patch​? It contains all my reviewer changes for doctests in the Sage library (i.e. all changes not for the doctest framework).

I'm running tests on OS X 10.6.8 with sage 5.7.beta1.

• Your changes to sage.calculus.test_sympy break doctests on my machine: they were correct before the change. Presumably these results are system dependent and should be changed somehow.

The difference is between plain ASCII characters and some fancy Unicode characters for the display. Not sure what to do with this.

• I get a bad exit in sage.misc.interpreter at line 132 (in get_test_shell()):

Did you apply #14070?

• There's still an error in sagenb.notebook.worksheet line 196: sagenb.notebook has no attribute misc. I've seen this before and it should be easy to fix.

Good, then please fix it.

How is 12415_review.patch​ coming along?

I think it works well for normal testing. I still have to think about --debug and things like --gdb. It seems it will be necessary to have a serial mode for example for --gdb, so I have to put that back in. I would also like to force --serial when --debug is used, mainly to simplify the code.

But first I'm going to look at #14079 on OS X.

[roed]

• Your changes to sage.calculus.test_sympy break doctests on my machine: they were correct before the change. Presumably these results are system dependent and should be changed somehow.

The difference is between plain ASCII characters and some fancy Unicode characters for the display. Not sure what to do with this.

I fixed it by temporarily turning off unicode in pretting printing. I updated the patch with this change.

• I get a bad exit in sage.misc.interpreter at line 132 (in get_test_shell()):

Did you apply #14070?

Nope: applying #14070 fixed the problem.

• There's still an error in sagenb.notebook.worksheet line 196: sagenb.notebook has no attribute misc. I've seen this before and it should be easy to fix.

Good, then please fix it.

Okay, the easy fix I remembered is to add a line to sagenb.notebook.worksheet:

         EXAMPLES: We test the constructor via an indirect doctest::
 
             sage: nb = sagenb.notebook.notebook.Notebook(tmp_dir()+'.sagenb')
+            sage: import sagenb.notebook.misc
             sage: sagenb.notebook.misc.notebook = nb
             sage: W = nb.create_new_worksheet('Test with unicode ěščřžýáíéďĎ', 'admin')
             sage: W

I haven't made any changes to sagenb for a long time. I assume this would require a new spkg?

How is 12415_review.patch​ coming along?

I think it works well for normal testing. I still have to think about --debug and things like --gdb. It seems it will be necessary to have a serial mode for example for --gdb, so I have to put that back in. I would also like to force --serial when --debug is used, mainly to simplify the code.

Makes sense.

But first I'm going to look at #14079 on OS X.

Good luck.

[jdemeyer]

Replying to roed:

I haven't made any changes to sagenb for a long time. I assume this would require a new spkg?

No, sagenb is now officially a separate project. I have sent a patch to "upstream" sagenb.

[jdemeyer]

New major update of my code. Now adds support for --debug.

I removed SagePdb since the motivation of the output-redirection in the Python doctesting framework seems to be doctesting Pdb itself, not running a debugger inside the doctesting framework. For the new doctesting framework, we just need to stop spoofing before entering the debugger and start spoofing after the debugger is finished and that's all.

[jdemeyer]

I fixed a few doctests errors, now the only remaining failure is

sage -t --long devel/sage/sage/doctest/sources.py
**********************************************************************
File "devel/sage/sage/doctest/sources.py", line 653, in sage.doctest.sources.FileDocTestSource._test_enough_doctests
Failed example:
    for path, dirs, files in itertools.chain(os.walk(sage_loc), os.walk(doc_loc)): # long time
        path = os.path.relpath(path)
        for F in files:
            _, ext = os.path.splitext(F)
            if ext in ('.py', '.pyx', '.sage', '.spyx', '.rst', '.tex'):
                filename = os.path.join(path, F)
                FDS = FileDocTestSource(filename, True, True, True, False)
                FDS._test_enough_doctests(verbose=False)
Expected:
    There are 3 unexpected tests being run in .../sage/doctest/parsing.py
    There are 1 tests in .../sage/ext/c_lib.pyx that are not being run
    There are 2 tests in .../sage/server/notebook/worksheet.py that are not being run
    There are 5 tests in .../doc/en/tutorial/interfaces.rst that are not being run
Got:
    doctest:229: UnicodeWarning: Unicode equal comparison failed to convert both arguments to Unicode - interpreting them as being unequal
    There are 2 tests in devel/sage/sage/server/notebook/worksheet.py that are not being run
    There are 2 unexpected tests being run in devel/sage/sage/misc/cython.py
    There are 9 tests in devel/sage/sage/graphs/graph_plot.py that are not being run
    There are 1 tests in devel/sage/sage/ext/c_lib.pyx that are not being run
    There are 3 unexpected tests being run in devel/sage/sage/doctest/parsing.py
    There are 5 tests in devel/sage/doc/en/tutorial/interfaces.rst that are not being run
    There are 1152 tests in devel/sage/doc/output/latex/en/reference/reference.tex that are not being run
    There are 51 tests in devel/sage/doc/output/latex/en/tutorial/SageTutorial.tex that are not being run
    There are 4 tests in devel/sage/doc/output/latex/en/thematic_tutorials/thematic_tutorials.tex that are not being run
    There are 6 tests in devel/sage/doc/output/latex/en/prep/prep_tutorials.tex that are not being run
    There are 2 tests in devel/sage/doc/output/latex/en/numerical_sage/numerical_sage.tex that are not being run
    There are 15 tests in devel/sage/doc/output/latex/en/developer/developer.tex that are not being run
    There are 16 tests in devel/sage/doc/output/latex/en/constructions/constructions.tex that are not being run
    There are 51 tests in devel/sage/doc/output/latex/ru/tutorial/SageTutorial_ru.tex that are not being run
    There are 51 tests in devel/sage/doc/output/latex/fr/tutorial/tutorial-fr.tex that are not being run
    There are 51 tests in devel/sage/doc/output/latex/de/tutorial/SageTutorial-de.tex that are not being run
**********************************************************************

And there are still messages about TABs in sagenb/data.

[jdemeyer]

I have been thinking about the encoding warnings (and encodings in doctests in general). I think there are two options:

1. either we ignore the Cython warnings and continue working with pure strings,
2. or we make the doctester completely Unicode-aware.

I don't really see any middle ground. I'm inclined to go for the first option initially, but eventually migrating to the second option in a different ticket.

But I'm open to opinions on this.

[roed]

Replying to jdemeyer:

I have been thinking about the encoding warnings (and encodings in doctests in general). I think there are two options:

1. either we ignore the Cython warnings and continue working with pure strings,
2. or we make the doctester completely Unicode-aware.

I don't really see any middle ground. I'm inclined to go for the first option initially, but eventually migrating to the second option in a different ticket.

But I'm open to opinions on this.

Sounds like a good plan to me. I prefer to avoid unicode when I can.

[jdemeyer]

With these patches + the patched sagenb (​https://github.com/sagemath/sagenb/pull/84), I get just one sporadic failure:

sage -t --long devel/sage/sage/homology/simplicial_complex.py
**********************************************************************
File "devel/sage/sage/homology/simplicial_complex.py", line 2188, in sage.homology.simplicial_complex.SimplicialComplex.is_cohen_macaulay
Failed example:
    S.is_cohen_macaulay(ncpus=3)
Expected:
    False
Got:
    Exception OSError: (10, 'No child processes') in <generator object __call__ at 0x646f1e0> ignored
    False
**********************************************************************

I have not investigated, but I assume it must be some strange interaction between the DocTestWorker processes and the cohen_macaulay subprocesses.

Since bsd.math has been down for a while (now it is back up), I haven't been able to look into the OS X issues.

I guess the only remaining issue is --gdb (and --valgrind...) support.

[roed]

So is this ready for review by me?

[jdemeyer]

Parallel testing still doesn't work on OS X. 1-process testing (-p 1) works.

[roed]

Do you know why parallel testing doesn't work?

[jdemeyer]

What's the point of running optional tests without optional "sage" tests? Because that would badly fail with code like

sage: a = some_object()
sage: a.some_standard_method()
sage: a.use_mypackage()  # optional: mypackage

(only the last line would be executed)

Are all doctests supposed to be written like

sage: a = some_object()
sage: a.some_standard_method()

sage: a = some_object()  # optional: mypackage
sage: a.use_mypackage()  # optional: mypackage

[roed]

Replying to jdemeyer:

What's the point of running optional tests without optional "sage" tests? Because that would badly fail with code like

sage: a = some_object()
sage: a.some_standard_method()
sage: a.use_mypackage()  # optional: mypackage

(only the last line would be executed)

Are all doctests supposed to be written like

sage: a = some_object()
sage: a.some_standard_method()

sage: a = some_object()  # optional: mypackage
sage: a.use_mypackage()  # optional: mypackage

I agree that the current implementation is kinda dumb. But I could see wanting to run sage -t --all --optional gap and have only files with optional gap tests be run.

[jdemeyer]

Replying to roed:

I agree that the current implementation is kinda dumb. But I could see wanting to run sage -t --all --optional gap and have only files with optional gap tests be run.

So this is basically an option waiting for a better future implementation?

[roed]

Replying to jdemeyer:

Replying to roed:

I agree that the current implementation is kinda dumb. But I could see wanting to run sage -t --all --optional gap and have only files with optional gap tests be run.

So this is basically an option waiting for a better future implementation?

Yeah, that's how I see it. I don't really run optional tests very often, but it seems like it could be useful to quickly run the tests that directly depend on gap when you update an spkg or something. But I'm not really attached to the particulars of the interface, so feel free to change it.

[jhpalmieri]

A question about this new framework: at #13928, it was pointed out that if you (for whatever reason) put the Sage directory into a directory whose path contains "/." (like "/home/user/.Sage-stuff/sage-5.8.beta0/"), then it will refuse to doctest any files in the Sage library. Will that still be true with this new setup? Basically, I'm wondering if this ticket supersedes #13928.

[jdemeyer]

Replying to jhpalmieri:

A question about this new framework: at #13928, it was pointed out that if you (for whatever reason) put the Sage directory into a directory whose path contains "/." (like "/home/user/.Sage-stuff/sage-5.8.beta0/")

Hiding Sage from the boss?

then it will refuse to doctest any files in the Sage library. Will that still be true with this new setup?

No, see sage/doctest/control.py, line 456.

[jhpalmieri]

Nathann has a reason for putting his entire Sage installation in a hidden directory. I can understand why we would skip testing files in directories within the Sage library that start with "." (like ".hg"), but why not just have that limitation and let the user put their Sage directory anywhere?

[jdemeyer]

Replying to jhpalmieri:

Nathann has a reason for putting his entire Sage installation in a hidden directory. I can understand why we would skip testing files in directories within the Sage library that start with "." (like ".hg"), but why not just have that limitation

I believe that's precisely what we're doing, unless I am mistaken.

[jdemeyer]

Sorry John, I misread your original question.

[jhpalmieri]

Okay, good, then I suggest that we close #13928 as a duplicate of this one, or at least close #13928 when this one is merged.

[ncohen]

I can understand why we would skip testing files in directories within the Sage library that start with "." (like ".hg"), but why not just have that limitation

I believe that's precisely what we're doing, unless I am mistaken.

Sorry, but I don't get it O_o

After this patch is applied, will all files be skipped if SAGE_ROOT contains a /. somewhere, even if it is not a /.hg ?

Nathann

[ncohen]

Okay, good, then I suggest that we close #13928 as a duplicate of this one, or at least close #13928 when this one is merged.

Gloops. That answers my question too :-)

Then I will set #13928 to "positive review/duplicate", as I can safely have faith in our release manager and this patch :-)

Nathann

[jhpalmieri]

What goes wrong with parallel testing on OS X? I've installed the patches on an OS X 10.8.2 box, and running ./sage -tp devel/sage/sage/homology devel/sage/sage/parallel/ works fine, correctly detecting two cores, and completing testing faster than ./sage -t .... Using ./sage -tp 3 ... runs even slightly faster.

[roed]

Replying to jhpalmieri:

What goes wrong with parallel testing on OS X? I've installed the patches on an OS X 10.8.2 box, and running ./sage -tp devel/sage/sage/homology devel/sage/sage/parallel/ works fine, correctly detecting two cores, and completing testing faster than ./sage -t .... Using ./sage -tp 3 ... runs even slightly faster.

Jeroen said at #14079 that the parallel testing problem on OS X should be fixed now.

[jdemeyer]

So far, OS X has not been my priority. I think it has to do with the way terminals are handled (try ./sage -t ... </dev/null 2>&1 | cat for example, completely bypassing terminal I/O)

[jdemeyer]

Concerning terminals, I also noted (on Linux) that piping output to less (./sage -t ... | less) doesn't quite work properly.

[jhpalmieri]

Without applying any of the patches here, if a user modifies their configuration, say via #14188, some doctests may fail. I assume the same will be true after applying the patches here. My question: should make ptest (etc.) run with the --nodotsage setting, while sage -t ... uses the user's configuration? Or should both use --nodotsage, or neither use it?

[roed]

Replying to jhpalmieri:

Without applying any of the patches here, if a user modifies their configuration, say via #14188, some doctests may fail. I assume the same will be true after applying the patches here. My question: should make ptest (etc.) run with the --nodotsage setting, while sage -t ... uses the user's configuration? Or should both use --nodotsage, or neither use it?

I would say that both should use it: I don't see why the user might need their custom configuration when doctesting.

[jhpalmieri]

I have a request/suggestion: move DOCTEST_MODE out of plot.py and into a file in the doctest directory. Right now, importing from plot.py can be lead to circular imports, etc. Also, it never belonged in plot.py in the first place. Can we do that on this ticket, or should it be on a followup?

[jpflori]

Replying to roed:

Do you ever use sage -t with valgrind? I'm not sure exactly what's wrong with sage -t --valgrind <FILENAME>.

It used to work and I used it at some point to deal with the nice random failures caused by the introduction of weak caches of #715. Note the optional spkg we currently propose is really old (and surely dysfunctional on most systems), but there's an update rotting at #13060. I wouldn't mind making valgrind working again a follow-up ticket as I'm not actively using it right now.

[jdemeyer]

Concerning DOT_SAGE: it's not as easy as you think. The problem is that the doctesting framework needs DOT_SAGE in a few places, for example to store the timing information. So running

sage --nodotsage -t ...

is not an option.

Perhaps changing $IPYTHONDIR is sufficient? That could be done within the doctesting framework.

[jdemeyer]

Replying to jhpalmieri:

I have a request/suggestion: move DOCTEST_MODE out of plot.py and into a file in the doctest directory. Right now, importing from plot.py can be lead to circular imports, etc. Also, it never belonged in plot.py in the first place. Can we do that on this ticket, or should it be on a followup?

This ticket is already big enough, so I created the follow-up #14203.

[roed]

All tests pass for me. I'm reading through 12415_review.patch​.

[jdemeyer]

Fixed a conflict (nothing serious) with #14054.

[roed]

Still working through 12415_review.patch​, but note that four functions in sage.doctest.forker don't have tests.

[roed]

Here's a review patch which adds doctests for the four functions that were missing them and makes a few other minor changes. Other than this, I'm happy with Jeroen's changes.

[jhpalmieri]

In 12415_review_review.patch​, line 693 of control.py, "sage.supp" got changed to "sage.sup". Was this intentional?

[jhpalmieri]

When I run make ptestlong, things look fine on the screen, but I see some funny characters in ptestlong.log (this is on OS X 10.8.2):

Doctesting 2283 files using 2 threads.
^[[?1034hsage -t --long devel/sage/sage/misc/interpreter.py
    [107 tests, 12.0 s]

So far, this is the only instance of this in the file. Could it be some sort of terminal color escape sequence? I see it on one machine but not another, so maybe it was just a cosmic ray...

[roed]

Replying to jhpalmieri:

In 12415_review_review.patch​, line 693 of control.py, "sage.supp" got changed to "sage.sup". Was this intentional?

Nope: thanks for catching that.

[jdemeyer]

Replying to jhpalmieri:

When I run make ptestlong, things look fine on the screen, but I see some funny characters in ptestlong.log (this is on OS X 10.8.2):

Doctesting 2283 files using 2 threads.
^[[?1034hsage -t --long devel/sage/sage/misc/interpreter.py
    [107 tests, 12.0 s]

So far, this is the only instance of this in the file. Could it be some sort of terminal color escape sequence?

Yes. It most likely comes from the import readline I added in init_sage() (this happens once, so it's normal you see it only once in ptestlong.log). I have been fighting quite a bit with terminal I/O in this new doctester, and this is yet another manifestion of terminal issues :-(

[jdemeyer]

Could you do me a favour since I don't have access to an OS X 10.8 system:

Remove that import readline statement and run

./sage -btp N --long devel/sage/sage/doctest devel/sage/sage/tests

in the following ways:

1. Normal doctest run in the terminal, let it finish
2. Interrupt (CTRL-C) the tests somewhere in the middle of the run
3. Pipe the output through less: ./sage -tp 2 ... | less

And all this both with -p 1 and with -p N for some N > 1.

[jdemeyer]

David, I noticed that doc/en/developer/doctesting.rst in 12415_doc.patch​ is full of TAB characters. Could you please replace those by 8 spaces?

I agree with 12415_review_review.patch​.

Did you also look at 12415_doctest_review.patch​, 12415_script_review.patch​ and 12415_test.patch​?

[jdemeyer]

Sorry, too fast. This is dangerous:

sage: W.start() 
sage: W.join() 
sage: while W.rmessages is not None: 
....:   W.read_messages() 
sage: len(W.messages) > 0 
True 

You should read the messages while the worker is running, because otherwise the pipe buffer might get full, leading to a block. So put W.join() at the end instead of at the beginning. Apart from that, it's a useful and good test.

[roed]

Replying to jdemeyer:

David, I noticed that doc/en/developer/doctesting.rst in 12415_doc.patch​ is full of TAB characters. Could you please replace those by 8 spaces?

That's ironic. I replaced them, though I left the ones you're deleting in 12415_review.patch​ so that it applies cleanly.

Did you also look at 12415_doctest_review.patch​, 12415_script_review.patch​ and 12415_test.patch​?

12415_doctest_review.patch​ and 12415_script_review.patch​ both look fine.

For 12415_test.patch​, you never run some of the files in the test directory (sig_on.rst and sleep_and_raise.rst). Otherwise they look good.

[roed]

Replying to jdemeyer:

Sorry, too fast. This is dangerous:

sage: W.start() 
sage: W.join() 
sage: while W.rmessages is not None: 
....:   W.read_messages() 
sage: len(W.messages) > 0 
True 

You should read the messages while the worker is running, because otherwise the pipe buffer might get full, leading to a block. So put W.join() at the end instead of at the beginning. Apart from that, it's a useful and good test.

Done. I also updated the tests for kill and save_result_output to be more robust.

[roed]

Replying to jdemeyer:

Could you do me a favour since I don't have access to an OS X 10.8 system:

Is this useful for me to run on OS X 10.6.8?

Remove that import readline statement and run

./sage -btp N --long devel/sage/sage/doctest devel/sage/sage/tests

in the following ways:

1. Normal doctest run in the terminal, let it finish
2. Interrupt (CTRL-C) the tests somewhere in the middle of the run
3. Pipe the output through less: ./sage -tp 2 ... | less

And all this both with -p 1 and with -p N for some N > 1.

[jdemeyer]

Replying to roed:

For 12415_test.patch​, you never run some of the files in the test directory (sig_on.rst and sleep_and_raise.rst).

Well, I found sleep_and_raise.rst useful for manual testing, so I left it.

And sig_on.rst will be tested in the follow-up #14152 (which will be an easy ticket).

[jhpalmieri]

On OS X 10.8.2.

Running with sage -btp 1 ...:

sage -t --long devel/sage/sage/tests/french_book/polynomes.py
/Users/palmieri/Desktop/Sage_stuff/sage_builds/sage-5.8.beta2/local/lib/python2.7/site-packages/Cython/Build/Dependencies.py:229: UnicodeWarning: Unicode equal comparison failed to convert both arguments to Unicode - interpreting them as being unequal
  if code[q-1] == u'\\':
    [107 tests, 2.6 s]

Running with sage -btp 2 ... — note the random (?) placement of the unicode warning:

sage -t --long devel/sage/sage/tests/book_stein_modform.py
    [239 tests, 3.3 s]
/Users/palmieri/Desktop/Sage_stuff/sage_builds/sage-5.8.beta2/local/lib/python2.7/site-packages/Cython/Build/Dependencies.py:229: UnicodeWarning: Unicode equal comparison failed to convert both arguments to Unicode - interpreting them as being unequal
  if code[q-1] == u'\\':
sage -t --long devel/sage/sage/tests/french_book/polynomes.py
    [107 tests, 2.3 s]

Without the import readline statement, I got one nonrepeatable failure with sage -btp 2 ... (probably has nothing to do with readline, but have you seen this before?):

sage -t --long devel/sage/sage/doctest/forker.py
**********************************************************************
File "devel/sage/sage/doctest/forker.py", line 1693, in sage.doctest.forker.DocTestWorker.read_messages
Failed example:
    while W.rmessages is not None:
        W.read_messages()
Exception raised:
    Traceback (most recent call last):
      File "/Users/palmieri/Desktop/Sage_stuff/sage_builds/sage-5.8.beta2/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 436, in _run
        self.execute(example, compiled, test.globs)
      File "/Users/palmieri/Desktop/Sage_stuff/sage_builds/sage-5.8.beta2/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 792, in execute
        exec compiled in globs
      File "<doctest sage.doctest.forker.DocTestWorker.read_messages[9]>", line 2, in <module>
        W.read_messages()
      File "/Users/palmieri/Desktop/Sage_stuff/sage_builds/sage-5.8.beta2/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 1703, in read_messages
        s = os.read(self.rmessages, 4096)
    OSError: [Errno 4] Interrupted system call
**********************************************************************
1 item had failures:
   1 of  13 in sage.doctest.forker.DocTestWorker.read_messages
    [384 tests, 1 failure, 17.3 s]

With or without the import readline statement, I see this when piping through less, with -btp 1 or -btp 2:

Installing c_lib
ESC[?1034hscons: `install' is up to date.

Except for the nonrepeatable failure, I see no difference with or without import readline.

[jdemeyer]

Replying to jhpalmieri:

sage -t --long devel/sage/sage/doctest/forker.py
**********************************************************************
File "devel/sage/sage/doctest/forker.py", line 1693, in sage.doctest.forker.DocTestWorker.read_messages
Failed example:
    while W.rmessages is not None:
        W.read_messages()
Exception raised:
    Traceback (most recent call last):
      File "/Users/palmieri/Desktop/Sage_stuff/sage_builds/sage-5.8.beta2/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 436, in _run
        self.execute(example, compiled, test.globs)
      File "/Users/palmieri/Desktop/Sage_stuff/sage_builds/sage-5.8.beta2/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 792, in execute
        exec compiled in globs
      File "<doctest sage.doctest.forker.DocTestWorker.read_messages[9]>", line 2, in <module>
        W.read_messages()
      File "/Users/palmieri/Desktop/Sage_stuff/sage_builds/sage-5.8.beta2/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 1703, in read_messages
        s = os.read(self.rmessages, 4096)
    OSError: [Errno 4] Interrupted system call
**********************************************************************
1 item had failures:
   1 of  13 in sage.doctest.forker.DocTestWorker.read_messages
    [384 tests, 1 failure, 17.3 s]

That actually looks serious, I'll have a look.

Installing c_lib
ESC[?1034hscons: `install' is up to date.

That's before the doctester starts, so it's not our problem.

Except for the nonrepeatable failure, I see no difference with or without import readline.

Is the [[?1034h control code gone when you remove import readline?

[jhpalmieri]

Is the [[?1034h control code gone when you remove import readline?

No, it's there either way.

[jhpalmieri]

Another random failure:

sage -t devel/sage/sage/doctest/forker.py
**********************************************************************
File "devel/sage/sage/doctest/forker.py", line 1729, in sage.doctest.forker.DocTestWorker.save_result_output
Failed example:
    sorted(W.result[1].keys())
Expected:
    ['cputime', 'err', 'failures', 'walltime']
Got:
    ['err']
**********************************************************************
1 item had failures:
   1 of  14 in sage.doctest.forker.DocTestWorker.save_result_output
    [384 tests, 1 failure, 17.4 s]

[jdemeyer]

Replying to jhpalmieri:

Is the [[?1034h control code gone when you remove import readline?

No, it's there either way.

In serial and in parallel?

[jdemeyer]

Updates documention

[jdemeyer]

• Merged two doctest patches

• Merged the patches to the documentation into 12415_doc.patch​ and changed version numbers to sage-5.9.

• 12415_test.patch​: removed unused sig_on.rst.

[jdemeyer]

John: I think both your failures are due to not resetting the SIGCHLD signal handler, that should be fixed now.

[roed]

Replying to jdemeyer:

John: I think both your failures are due to not resetting the SIGCHLD signal handler, that should be fixed now.

I still get the following failures:

sage -t sage/doctest/forker.py
**********************************************************************
File "sage/doctest/forker.py", line 1777, in sage.doctest.forker.DocTestWorker.kill
Failed example:
    W.kill()
Exception raised:
    Traceback (most recent call last):
      File "/Users/roed/sage/sage-5.8.beta0/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 432, in _run
        self.execute(example, compiled, test.globs)
      File "/Users/roed/sage/sage-5.8.beta0/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 788, in execute
        exec compiled in globs
      File "<doctest sage.doctest.forker.DocTestWorker.kill[14]>", line 1, in <module>
        W.kill()
      File "/Users/roed/sage/sage-5.8.beta0/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 1791, in kill
        os.killpg(self.pid, signal.SIGHUP)
    OSError: [Errno 3] No such process
**********************************************************************
File "sage/doctest/forker.py", line 1781, in sage.doctest.forker.DocTestWorker.kill
Failed example:
    W.kill()         # Worker dies now
Exception raised:
    Traceback (most recent call last):
      File "/Users/roed/sage/sage-5.8.beta0/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 432, in _run
        self.execute(example, compiled, test.globs)
      File "/Users/roed/sage/sage-5.8.beta0/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 788, in execute
        exec compiled in globs
      File "<doctest sage.doctest.forker.DocTestWorker.kill[17]>", line 1, in <module>
        W.kill()         # Worker dies now
      File "/Users/roed/sage/sage-5.8.beta0/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 1793, in kill
        os.killpg(self.pid, signal.SIGKILL)
    OSError: [Errno 1] Operation not permitted
**********************************************************************

[jdemeyer]

Got it! It's trying to kill the process group, but we're not sure at this point that the worker already changed its process group.

[jdemeyer]

David: thanks for your added doctests. They really did expose some bugs.

[roed]

Excellent! I suspect there's more trouble somewhere, but I would suggest dealing with it in follow-up tickets.

The changes all look fine to me, but I haven't run full doctests (and am probably not going to be able to today since I'm traveling). I'm happy giving this positive review subject to all doctests passing.

[jdemeyer]

Doctest changes that are needed to account for differences in the new framework

[jdemeyer]

Rebased again.

I take David's comment as meaning "positive review".

[jdemeyer]

12415_manifest.patch​ needs review.

[roed]

Replying to jdemeyer:

12415_manifest.patch​ needs review.

It looks fine to me, though I don't see why it's relevant to doctesting.

[jdemeyer]

Replying to roed:

I don't see why it's relevant to doctesting.

My patch adds .rst files (mainly because I wanted to use something else than .py files for a change).

[jdemeyer]

Further testing revealed some more subtle problems. I will simply extend the file 12415_rebase_58.patch​ until this ticket is ready to be merged.