Opened 8 years ago

Last modified 7 years ago

#12415 closed enhancement

Update doctesting framework — at Version 193

Reported by: robertwb Owned by: jdemeyer
Priority: major Milestone: sage-5.9
Component: doctest framework Keywords:
Cc: kini, ohanar, jhpalmieri Merged in:
Authors: David Roe, Robert Bradshaw Reviewers: Jeroen Demeyer
Report Upstream: N/A Work issues:
Branch: Commit:
Dependencies: #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871, #13195, #13121, #13748, #13899, #12719, #5155, #14070, #14079 Stopgaps:

Description (last modified by jdemeyer)

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/

and does most of the above (plus more which has been moved to followup tickets #12720 and #12722)

Apply 12415_framework.patch, 12415_doctest_fixes.patch, 12415_doctest_review.patch, 12415_doc.patch, 12415_review.patch

Apply 12415_script.patch to the scripts repo

Apply 12415_spkg_bin_sage.patch to the root repo

Change History (196)

comment:1 Changed 8 years ago by robertwb

  • Description modified (diff)

comment:2 Changed 8 years ago by robertwb

  • Description modified (diff)

comment:3 Changed 8 years ago by roed

  • Description modified (diff)

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

comment:4 Changed 8 years ago by roed

  • Description modified (diff)

comment:5 Changed 8 years ago by roed

  • Description modified (diff)

comment:6 Changed 8 years ago by roed

  • Dependencies set to #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384

comment:7 Changed 8 years ago by roed

  • Dependencies changed from #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384 to #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384

comment:8 Changed 8 years ago by kini

  • Cc kini added

comment:9 Changed 8 years ago by 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?)

comment:10 Changed 8 years ago by ohanar

  • Cc ohanar added

comment:11 Changed 8 years ago by ohanar

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

comment:12 Changed 8 years ago by roed

  • Dependencies changed from #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384 to #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384

comment:13 Changed 8 years ago by roed

  • Dependencies changed from #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384 to #13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384

comment:14 Changed 8 years ago by roed

  • Dependencies changed from #13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384 to #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384

comment:15 Changed 8 years ago by roed

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

comment:16 Changed 8 years ago by jhpalmieri

  • Cc jhpalmieri added

comment:17 Changed 8 years ago by roed

  • Description modified (diff)

comment:18 Changed 8 years ago by roed

  • Description modified (diff)

comment:19 Changed 8 years ago by roed

  • Status changed from new to needs_review

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.

comment:20 Changed 8 years ago by 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

comment:21 Changed 8 years ago by roed

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

comment:22 Changed 8 years ago by roed

  • Description modified (diff)

comment:23 Changed 8 years ago by 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.

comment:24 Changed 8 years ago by jhpalmieri

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

comment:25 Changed 8 years ago by 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()).

comment:26 Changed 8 years ago by jhpalmieri

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

  • sage-runtests

    diff --git a/sage-runtests b/sage-runtests
    a b import optparse, os, sys 
    55if __name__ == "__main__":
    66    parser = optparse.OptionParser()
    77
    8     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())")
     8    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())")
    99    parser.add_option("--serial", action="store_true", default=False, help="run tests in a single process in series")
    1010    parser.add_option("--timeout", type=int, default=-1, help="timeout (in seconds) for doctesting one file")
    1111    parser.add_option("-a", "--all", action="store_true", default=False, help="test all files in the Sage library")
    if __name__ == "__main__": 
    4949    parser.add_option("--stats_path", "--stats-path", default=os.path.join(os.path.expanduser("~/.sage/timings2.json")), \
    5050                          help="path to a json dictionary for the latest run storing a timing for each file")
    5151
     52    options, args = parser.parse_args()
     53    try:
     54        options.nthreads = int(options.nthreads)
     55    except ValueError:
     56        args.insert(0, options.nthreads.strip())
     57        options.nthreads = 0
     58
     59    if options.nthreads == 0:
     60        try:
     61            options.nthreads = int(os.environ['SAGE_NUM_THREADS_PARALLEL'])
     62        except KeyError:
     63            options.nthreads = 1
     64
    5265    from sage.doctest.control import DocTestController
    53     DC = DocTestController(*parser.parse_args())
     66    DC = DocTestController(options, args)
    5467    err = DC.run()
    5568    sys.exit(err)

and for the Sage library:

  • sage/doctest/control.py

    diff --git a/sage/doctest/control.py b/sage/doctest/control.py
    a b class DocTestController(SageObject): 
    433433            else:
    434434                nother += 1
    435435        if nfiles + ndbsources + nother:
    436             self.log("Doctesting %s."%(", ".join((["%s file%s"%(nfiles, "s" if nfiles > 1 else "")] if nfiles else []) +
    437                                                  (["%s other sources"%nother] if nother else []))))
     436            self.log("Doctesting %s"%(", ".join((["%s file%s"%(nfiles, "s" if nfiles > 1 else "")] if nfiles else []) +
     437                                                 (["%s other sources"%nother] if nother else [])))
     438                + " using %s threads."%self.options.nthreads if self.options.nthreads > 1 else ".")
    438439            self.reporter = DocTestReporter(self)
    439440            self.dispatcher = DocTestDispatcher(self)
    440441            try:

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

comment:27 Changed 8 years ago by 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!).

comment:28 Changed 8 years ago by roed

  • Description modified (diff)

comment:29 Changed 8 years ago by jdemeyer

sage/parallel/decorate.py: Use

Unhandled SIG...

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

comment:30 Changed 8 years ago by jdemeyer

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

comment:31 Changed 8 years ago by 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)

comment:32 Changed 8 years ago by 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.

Last edited 8 years ago by jdemeyer (previous) (diff)

comment:33 follow-up: Changed 8 years ago by jdemeyer

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

comment:34 in reply to: ↑ 33 Changed 8 years ago by 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)
...

comment:35 Changed 8 years ago by 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:

comment:36 Changed 8 years ago by 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)

comment:37 Changed 8 years ago by jdemeyer

  • Status changed from needs_review to needs_work

comment:38 follow-up: Changed 8 years ago by jdemeyer

  • Reviewers set to Jeroen Demeyer

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

comment:39 Changed 8 years ago by jdemeyer

  • Authors set to David Roe, Robert Bradshaw

comment:40 Changed 8 years ago by 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?

comment:41 Changed 8 years ago by 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

comment:42 in reply to: ↑ 38 Changed 8 years ago by jdemeyer

Replying to jdemeyer:

Planning to make a reviewer patch

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

comment:43 follow-up: Changed 8 years ago by 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.

comment:44 Changed 8 years ago by roed

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

comment:45 Changed 8 years ago by roed

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

comment:46 follow-up: Changed 8 years ago by 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.

Last edited 8 years ago by roed (previous) (diff)

comment:47 in reply to: ↑ 43 Changed 8 years ago by 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.

Last edited 8 years ago by jdemeyer (previous) (diff)

comment:48 follow-up: Changed 8 years ago by 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).

comment:49 in reply to: ↑ 48 Changed 8 years ago by 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.

comment:50 follow-ups: Changed 8 years ago by 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?

comment:51 Changed 8 years ago by roed

  • Status changed from needs_work to needs_review

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

comment:52 in reply to: ↑ 50 Changed 8 years ago by 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.

comment:53 in reply to: ↑ 50 Changed 8 years ago by 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.

comment:54 Changed 8 years ago by 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.

comment:55 Changed 8 years ago by 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.
  1. The fact that sage -t foo is written instead of sage -t --long foo.
  1. 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!

Last edited 8 years ago by jdemeyer (previous) (diff)

comment:56 Changed 8 years ago by 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
    ======================================================================
**********************************************************************
Last edited 8 years ago by jdemeyer (previous) (diff)

comment:57 Changed 8 years ago by 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.

Last edited 8 years ago by jdemeyer (previous) (diff)

comment:58 Changed 8 years ago by 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.

comment:59 Changed 8 years ago by 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.

Last edited 8 years ago by jdemeyer (previous) (diff)

comment:60 follow-up: Changed 8 years ago by jdemeyer

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

comment:61 Changed 8 years ago by 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

comment:62 follow-up: Changed 8 years ago by jdemeyer

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

comment:63 follow-ups: Changed 8 years ago by 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

comment:64 Changed 8 years ago by roed

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

comment:65 in reply to: ↑ 60 ; follow-up: Changed 8 years ago by 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.

comment:66 in reply to: ↑ 62 Changed 8 years ago by 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....

comment:67 Changed 8 years ago by 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).

comment:68 in reply to: ↑ 63 ; follow-ups: Changed 8 years ago by 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?

comment:69 in reply to: ↑ 68 Changed 8 years ago by 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).

Last edited 8 years ago by roed (previous) (diff)

comment:70 follow-up: Changed 8 years ago by 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.

comment:71 in reply to: ↑ 63 ; follow-up: Changed 8 years ago by 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.

comment:72 in reply to: ↑ 70 ; follow-up: Changed 8 years ago by 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.

comment:73 in reply to: ↑ 71 ; follow-up: Changed 8 years ago by 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).

comment:74 in reply to: ↑ 68 ; follow-up: Changed 8 years ago by 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?

comment:75 in reply to: ↑ 72 ; follow-up: Changed 8 years ago by 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....

Last edited 8 years ago by roed (previous) (diff)

comment:76 in reply to: ↑ 73 Changed 8 years ago by 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.

comment:77 in reply to: ↑ 74 Changed 8 years ago by 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.

comment:78 in reply to: ↑ 46 Changed 8 years ago by 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!

comment:79 in reply to: ↑ 75 ; follow-up: Changed 8 years ago by 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.)

Last edited 8 years ago by jdemeyer (previous) (diff)

comment:80 in reply to: ↑ 65 ; follow-up: Changed 8 years ago by 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.

comment:81 in reply to: ↑ 80 ; follow-ups: Changed 8 years ago by 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.

comment:82 in reply to: ↑ 81 Changed 8 years ago by 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>.

comment:83 in reply to: ↑ 79 Changed 8 years ago by 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.

comment:84 Changed 8 years ago by roed

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

comment:85 Changed 8 years ago by 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?

comment:86 Changed 8 years ago by 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.

comment:87 Changed 8 years ago by jdemeyer

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

comment:88 Changed 8 years ago by jdemeyer

  • Description modified (diff)

comment:89 follow-up: Changed 8 years ago by jdemeyer

  • Dependencies changed from #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384 to #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871
  • Status changed from needs_review to needs_work

Needs to be rebased to #11871.

comment:90 in reply to: ↑ 89 Changed 8 years ago by roed

Replying to jdemeyer:

Needs to be rebased to #11871.

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

comment:91 Changed 8 years ago by roed

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

comment:92 Changed 8 years ago by 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]
Last edited 8 years ago by jdemeyer (previous) (diff)

comment:93 Changed 8 years ago by 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.

comment:94 follow-up: Changed 8 years ago by roed

  • Status changed from needs_work to needs_review

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.

comment:95 Changed 8 years ago by jdemeyer

  • Dependencies changed from #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871 to #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871, #13195

comment:96 Changed 8 years ago by jdemeyer

Rebased the scripts patch to sage-5.1.

comment:97 Changed 8 years ago by jdemeyer

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

comment:98 in reply to: ↑ 94 ; follow-up: Changed 8 years ago by 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.

comment:99 in reply to: ↑ 98 Changed 8 years ago by 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.

comment:100 Changed 8 years ago by 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.

comment:101 Changed 8 years ago by roed

  • Description modified (diff)

I updated the sagenb patch

comment:102 Changed 8 years ago by kini

  • Description modified (diff)

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?

Last edited 8 years ago by kini (previous) (diff)

comment:103 follow-up: Changed 8 years ago by 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.

comment:104 in reply to: ↑ 103 Changed 8 years ago by 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.

comment:105 follow-up: Changed 8 years ago by jdemeyer

  • Status changed from needs_review to needs_work

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"

comment:106 follow-up: Changed 8 years ago by 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...

comment:107 Changed 8 years ago by 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.

comment:108 Changed 8 years ago by 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?)

comment:109 in reply to: ↑ 106 Changed 8 years ago by 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.

Last edited 8 years ago by roed (previous) (diff)

comment:110 in reply to: ↑ 105 Changed 8 years ago by 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.

comment:111 follow-up: Changed 8 years ago by 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")

comment:112 in reply to: ↑ 111 Changed 8 years ago by 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.

comment:113 Changed 8 years ago by kini

Ping - should this still be needs_work?

comment:114 Changed 8 years ago by jdemeyer

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

comment:115 Changed 8 years ago by 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.

comment:116 Changed 8 years ago by 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.

comment:117 Changed 8 years ago by roed

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

comment:118 Changed 8 years ago by roed

  • Work issues set to intermittent interrupt.pyx failure

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.

comment:119 Changed 8 years ago by 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.

comment:120 Changed 8 years ago by roed

  • Dependencies changed from #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871, #13195 to #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871, #13195, #13121
  • Description modified (diff)

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.

comment:121 Changed 8 years ago by 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?

comment:122 Changed 8 years ago by roed

  • Work issues changed from intermittent interrupt.pyx failure to interrupt.pyx failure

comment:123 Changed 8 years ago by jdemeyer

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

comment:124 Changed 8 years ago by roed

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

comment:125 Changed 8 years ago by jhpalmieri

  • Description modified (diff)

comment:126 Changed 8 years ago by 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

    diff --git a/sage/tests/interrupt.pyx b/sage/tests/interrupt.pyx
    a b def test_sig_block(long delay = DEFAULT_ 
    691691    TESTS::
    692692
    693693        sage: from sage.tests.interrupt import *
    694         sage: test_sig_block()
    695         42
    696694    """
    697695    cdef volatile_int v = 0
    698696

or

  • sage/tests/interrupt.pyx

    diff --git a/sage/tests/interrupt.pyx b/sage/tests/interrupt.pyx
    a b def test_signal_during_malloc(long delay 
    741741
    742742    TESTS::
    743743
    744         sage: from sage.tests.interrupt import *
    745         sage: for i in range(4):  # Several times to reduce chances of false positive
    746         ...       test_signal_during_malloc()
    747744    """
    748745    signal_after_delay(SIGINT, delay)
    749746    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?

comment:127 Changed 8 years ago by 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.

comment:128 Changed 8 years ago by 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.

comment:129 Changed 8 years ago by 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.

comment:130 Changed 8 years ago by roed

  • Dependencies changed from #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871, #13195, #13121 to #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871, #13195, #13121,#13748

comment:131 follow-up: Changed 8 years ago by 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?

comment:132 in reply to: ↑ 131 Changed 8 years ago by 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?

comment:133 Changed 8 years ago by jdemeyer

  • Description modified (diff)

comment:134 Changed 8 years ago by jdemeyer

Rebased and merged the two doctest patches.

comment:135 Changed 8 years ago by jdemeyer

  • Description modified (diff)

comment:136 Changed 8 years ago by jdemeyer

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

comment:137 Changed 8 years ago by jdemeyer

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

comment:138 follow-up: Changed 8 years ago by 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....

comment:139 Changed 8 years ago by jdemeyer

  • Dependencies changed from #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871, #13195, #13121,#13748 to #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871, #13195, #13121,#13748, #13899
  • Work issues interrupt.pyx failure deleted

comment:140 Changed 8 years ago by 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.

comment:141 Changed 8 years ago by jdemeyer

  • Dependencies changed from #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871, #13195, #13121,#13748, #13899 to #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871, #13195, #13121, #13748, #13899

comment:142 follow-up: Changed 8 years ago by 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.

comment:143 follow-up: Changed 8 years ago by 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.

comment:144 Changed 8 years ago by jdemeyer

Typo:

Comparison ist just comparison of the underlying lists.

comment:145 in reply to: ↑ 138 Changed 8 years ago by 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.

comment:146 in reply to: ↑ 143 Changed 8 years ago by 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.

comment:147 Changed 8 years ago by jdemeyer

#13908 might also help with proper killing.

comment:148 in reply to: ↑ 142 Changed 8 years ago by 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.

comment:149 Changed 7 years ago by fbissey

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

comment:150 Changed 7 years ago by 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.

comment:151 Changed 7 years ago by jdemeyer

  • Description modified (diff)

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.

Changed 7 years ago by jdemeyer

Apply to root repository

comment:152 Changed 7 years ago by jdemeyer

  • Dependencies changed from #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871, #13195, #13121, #13748, #13899 to #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871, #13195, #13121, #13748, #13899, #12719, #5155

Changed 7 years ago by jdemeyer

Patch to script repo; now removes old files

comment:153 follow-up: Changed 7 years ago by 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]]

comment:154 in reply to: ↑ 153 Changed 7 years ago by 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.

comment:155 Changed 7 years ago by jdemeyer

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

comment:156 follow-up: Changed 7 years ago by 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.

comment:157 in reply to: ↑ 156 Changed 7 years ago by 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).

Changed 7 years ago by roed

The new doctesting code

comment:158 Changed 7 years ago by 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.

comment:159 Changed 7 years ago by jdemeyer

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

comment:160 Changed 7 years ago by 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]

comment:161 Changed 7 years ago by jdemeyer

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

comment:162 Changed 7 years ago by 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()

comment:163 in reply to: ↑ 81 Changed 7 years ago by 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.

comment:164 Changed 7 years ago by jdemeyer

  • Description modified (diff)

comment:165 Changed 7 years ago by jdemeyer

  • Dependencies changed from #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871, #13195, #13121, #13748, #13899, #12719, #5155 to #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871, #13195, #13121, #13748, #13899, #12719, #5155, #14070

comment:166 Changed 7 years ago by 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'
**********************************************************************

comment:167 Changed 7 years ago by 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.

comment:168 Changed 7 years ago by jdemeyer

  • Dependencies changed from #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871, #13195, #13121, #13748, #13899, #12719, #5155, #14070 to #13147,#13146, #13145, #12723, #12392, #12393, #12395, #12396, #12397, #12381, #12382, #12383, #12384, #11871, #13195, #13121, #13748, #13899, #12719, #5155, #14070, #14079

comment:169 follow-up: Changed 7 years ago by 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).

Last edited 7 years ago by jdemeyer (previous) (diff)

comment:170 in reply to: ↑ 169 ; follow-up: Changed 7 years ago by 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.

comment:171 in reply to: ↑ 170 ; follow-up: Changed 7 years ago by 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.

comment:172 in reply to: ↑ 171 ; follow-up: Changed 7 years ago by 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?

comment:173 in reply to: ↑ 172 Changed 7 years ago by 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.

comment:174 follow-up: Changed 7 years ago by 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?

comment:175 in reply to: ↑ 174 ; follow-up: Changed 7 years ago by 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.

comment:176 in reply to: ↑ 175 Changed 7 years ago by 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.

comment:177 follow-up: Changed 7 years ago by 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.

comment:178 follow-up: Changed 7 years ago by jdemeyer

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

comment:179 in reply to: ↑ 178 Changed 7 years ago by 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.

comment:180 in reply to: ↑ 177 Changed 7 years ago by 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.

comment:181 follow-ups: Changed 7 years ago by 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?

Last edited 7 years ago by jdemeyer (previous) (diff)

comment:182 in reply to: ↑ 181 Changed 7 years ago by 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.

comment:183 Changed 7 years ago by jdemeyer

  • Owner changed from mvngu to jdemeyer

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

comment:184 in reply to: ↑ 181 Changed 7 years ago by 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.

comment:185 follow-up: Changed 7 years ago by jdemeyer

First version of my updated doctesting framework.

comment:186 in reply to: ↑ 185 ; follow-up: Changed 7 years ago by 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.

comment:187 in reply to: ↑ 186 Changed 7 years ago by 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.

comment:188 Changed 7 years ago by jdemeyer

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

comment:189 follow-up: Changed 7 years ago by 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?...

comment:190 in reply to: ↑ 189 ; follow-up: Changed 7 years ago by 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.

Last edited 7 years ago by roed (previous) (diff)

comment:191 in reply to: ↑ 190 ; follow-up: Changed 7 years ago by 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?

comment:192 in reply to: ↑ 191 Changed 7 years ago by 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.

comment:193 Changed 7 years ago by jdemeyer

  • Description modified (diff)
  • Milestone changed from sage-5.7 to sage-5.8

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).

Note: See TracTickets for help on using tickets.