Ticket #12415: 12415_review.patch

File 12415_review.patch, 144.8 KB (added by jdemeyer, 7 years ago)
  • sage/doctest/all.py

    # HG changeset patch
    # User Jeroen Demeyer <jdemeyer@cage.ugent.be>
    # Date 1361712186 -3600
    # Node ID 660c1254457a40cd6188ac8033e6a66289f97855
    # Parent  2deca38587e4bdbbbf411ff2c552dbf252e12cef
    Doctest framework: reviewer patch
    
    diff --git a/sage/doctest/all.py b/sage/doctest/all.py
    a b  
    1 from control import run_doctests
     1from sage.misc.lazy_import import lazy_import
     2lazy_import('sage.doctest.control', 'run_doctests')
  • sage/doctest/control.py

    diff --git a/sage/doctest/control.py b/sage/doctest/control.py
    a b  
    1212#                          William Stein <wstein@gmail.com>
    1313#
    1414#  Distributed under the terms of the GNU General Public License (GPL)
    15 #
     15#  as published by the Free Software Foundation; either version 2 of
     16#  the License, or (at your option) any later version.
    1617#                  http://www.gnu.org/licenses/
    1718#*****************************************************************************
    1819
    19 import random, glob, os, time, json, re, types
    20 from util import NestedName, Timer, count_noun
     20import random, os, sys, time, json, re, types
    2121import sage.misc.flatten
    2222from sage.structure.sage_object import SageObject
     23from sage.misc.misc import DOT_SAGE
    2324
    2425from sources import FileDocTestSource, DictAsObject
    2526from forker import DocTestDispatcher
    2627from reporting import DocTestReporter
     28from util import NestedName, Timer, count_noun, dict_difference
    2729
    28 branch_matcher = re.compile(r"^(sage(\-[A-Za-z0-9_\-\.]+)?" + os.path.sep + ")?sage(.*)")
    29 tested_extensions = [".py",".pyx",".pxi"]
    30 file_ext = re.compile("(.*)(" + "|".join(["\\" + a for a in tested_extensions]) + ")")
    3130
    3231class DocTestDefaults(SageObject):
    3332    """
    3433    This class is used for doctesting the Sage doctest module.
    3534
    36     It fills in attributes to be the defaults defined in SAGE_ROOT/local/bin/sage-runtests.
     35    It fills in attributes to be the same as the defaults defined in
     36    ``SAGE_ROOT/local/bin/sage-runtests``, expect for a few places,
     37    which is mostly to make doctesting more predictable.
    3738
    3839    EXAMPLES::
    3940
    4041        sage: from sage.doctest.control import DocTestDefaults
    41         sage: D = DocTestDefaults(); D.timeout
     42        sage: D = DocTestDefaults()
     43        sage: D
     44        DocTestDefaults()
     45        sage: D.timeout
    4246        -1
     47
     48    Keyword arguments become attributes::
     49
     50        sage: D = DocTestDefaults(timeout=100)
     51        sage: D
     52        DocTestDefaults(timeout=100)
     53        sage: D.timeout
     54        100
    4355    """
    4456    def __init__(self, **kwds):
    4557        """
     
    6173        self.warn_long = None
    6274        self.optional = "sage"
    6375        self.randorder = None
    64         self.global_iterations = 0
    65         self.file_iterations = 0
     76        self.global_iterations = 1  # sage-runtests default is 0
     77        self.file_iterations = 1    # sage-runtests default is 0
    6678        self.initial = False
    6779        self.force_lib = False
    68         self.abspath = True # We don't use the cmd line default so that doctest output is more predictable
     80        self.abspath = True         # sage-runtests default is False
    6981        self.verbose = False
    7082        self.debug = False
    7183        self.gdb = False
     
    7789        self.new = False
    7890        # We don't want to use the real stats file by default so that
    7991        # we don't overwrite timings for the actual running doctests.
    80         self.stats_path = os.path.join(os.path.expanduser("~/.sage/timings_dt_test.json"))
     92        self.stats_path = os.path.join(DOT_SAGE, "timings_dt_test.json")
    8193        if not os.path.exists(self.stats_path):
    8294            with open(self.stats_path, "w") as stats_file:
    8395                json.dump({},stats_file)
    8496        self.__dict__.update(kwds)
    8597
     98    def _repr_(self):
     99        """
     100        Return the print representation.
     101
     102        EXAMPLES::
     103
     104            sage: from sage.doctest.control import DocTestDefaults
     105            sage: DocTestDefaults(timeout=100, foobar="hello")
     106            DocTestDefaults(foobar='hello', timeout=100)
     107        """
     108        s = "DocTestDefaults("
     109        for k in sorted(dict_difference(self.__dict__, DocTestDefaults().__dict__).keys()):
     110            if s[-1] != "(":
     111                s += ", "
     112            s += str(k) + "=" + repr(getattr(self,k))
     113        s += ")"
     114        return s
     115
     116
    86117class DocTestController(SageObject):
    87118    """
    88119    This class controls doctesting of files.
     
    109140        # First we modify options to take environment variables into
    110141        # account and check compatibility of the user's specified
    111142        # options.
    112         if options.timeout == -1:
    113             if options.gdb or options.valgrind or options.massif or options.cachegrind or options.omega or options.debug:
    114                 options.timeout = os.getenv('SAGE_TIMEOUT_VALGRIND', 1024 * 1024)
     143        if options.timeout < 0:
     144            if options.gdb or options.debug:
     145                # Interactive debuggers: "infinite" timeout
     146                options.timeout = 0
     147            elif options.valgrind or options.massif or options.cachegrind or options.omega:
     148                # Non-interactive debuggers: 48 hours
     149                options.timeout = os.getenv('SAGE_TIMEOUT_VALGRIND', 48 * 60 * 60)
    115150            elif options.long:
    116151                options.timeout = os.getenv('SAGE_TIMEOUT_LONG', 30 * 60)
    117152            else:
    118153                options.timeout = os.getenv('SAGE_TIMEOUT', 5 * 60)
    119         if not hasattr(options, 'nthreads'):
    120             options.nthreads = 1
    121         elif options.nthreads == 0:
     154        if options.nthreads == 0:
    122155            options.nthreads = int(os.getenv('SAGE_NUM_THREADS_PARALLEL',1))
    123         if not hasattr(options, 'warn_long'):
    124             options.warn_long = None
    125156        if options.failed and not (args or options.new or options.sagenb):
    126157            # If the user doesn't specify any files then we rerun all failed files.
    127158            options.all = True
     
    129160            options.global_iterations = int(os.environ.get('SAGE_TEST_GLOBAL_ITER', 1))
    130161        if options.file_iterations == 0:
    131162            options.file_iterations = int(os.environ.get('SAGE_TEST_ITER', 1))
     163        if options.debug and options.nthreads > 1:
     164            print("Debugging requires single-threaded operation, setting number of threads to 1.")
     165            options.nthreads = 1
     166        if options.serial:
     167            options.nthreads = 1
     168
    132169        self.options = options
    133170        self.files = args
    134171        if options.all and options.logfile is None:
     
    143180            self.logfile = None
    144181        self.stats = {}
    145182        self.load_stats(options.stats_path)
    146         if (options.serial or options.verbose) and self.options.nthreads > 1:
    147             self.log("You may only use one thread when in verbose mode; resetting number of threads")
    148             self.options.nthreads = 1
    149183
    150184    def _repr_(self):
    151185        """
     
    164198        """
    165199        Load stats from the most recent run(s).
    166200
    167         Stats are stored as a JSON file, and include information on
    168         which files failed tests and the walltime used for execution of the doctests.
     201        Stats are stored as a JSON file, and include information on
     202        which files failed tests and the walltime used for execution
     203        of the doctests.
    169204
    170205        EXAMPLES::
    171206
     
    173208            sage: DC = DocTestController(DocTestDefaults(), [])
    174209            sage: import json
    175210            sage: filename = tmp_filename()
    176             sage: with open(filename, 'w') as stats_file: 
     211            sage: with open(filename, 'w') as stats_file:
    177212            ...       json.dump({'sage.doctest.control':{u'walltime':1.0r}}, stats_file)
    178213            sage: DC.load_stats(filename)
    179214            sage: DC.stats['sage.doctest.control']
     
    182217        try:
    183218            with open(filename) as stats_file:
    184219                self.stats.update(json.load(stats_file))
    185         except IOError:
    186             pass
    187         #except (ValueError, TypeError):
    188         #    self.log("Error loading stats from %s"%filename)
     220        except StandardError:
     221            self.log("Error loading stats from %s"%filename)
    189222
    190223    def save_stats(self, filename):
    191224        """
     
    201234            sage: filename = tmp_filename()
    202235            sage: DC.save_stats(filename)
    203236            sage: import json
    204             sage: with open(filename) as stats_file:
    205             ...       D = json.load(stats_file)
     237            sage: D = json.load(open(filename))
    206238            sage: D['sage.doctest.control']
    207239            {u'walltime': 1.0}
    208240        """
    209         try:
    210             with open(filename, 'w') as stats_file:
    211                 json.dump(self.stats, stats_file)
    212         except (IOError, ValueError, TypeError):
    213             raise
    214             #self.log("Error saving stats to %s"%filename)
     241        with open(filename, 'w') as stats_file:
     242            json.dump(self.stats, stats_file)
    215243
    216     def log(self, s):
     244    def log(self, s, end="\n"):
    217245        """
    218         Logs the string s to the logfile and prints it to standard out.
     246        Logs the string ``s + end`` (where ``end`` is a newline by default)
     247        to the logfile and prints it to the standard output.
    219248
    220249        EXAMPLES::
    221250
    222251            sage: from sage.doctest.control import DocTestDefaults, DocTestController
    223             sage: DD = DocTestDefaults(); DD.logfile = tmp_filename()
     252            sage: DD = DocTestDefaults(logfile=tmp_filename())
    224253            sage: DC = DocTestController(DD, [])
    225254            sage: DC.log("hello world")
    226255            hello world
     
    229258            hello world
    230259
    231260        """
     261        s += end
    232262        if self.logfile is not None:
    233             self.logfile.write(s + "\n")
    234         print(s)
     263            self.logfile.write(s)
     264        sys.stdout.write(s)
    235265
    236     def test_safe_directory(self, dir = None):
     266    def test_safe_directory(self, dir=None):
    237267        """
    238268        Test that the given directory is safe to run Python code from.
    239269
    240270        We use the check added to Python for this, which gives a
    241271        warning when the current directory is considered unsafe.  We promote
    242         this warning to an error with -Werror.  See sage/tests/cmdline.py
    243         for a doctest that this works, see also :trac:`13579`.
     272        this warning to an error with ``-Werror``.  See
     273        ``sage/tests/cmdline.py`` for a doctest that this works, see
     274        also :trac:`13579`.
    244275
    245276        TESTS::
    246277
     
    256287            ...
    257288            RuntimeError: refusing to run doctests...
    258289        """
    259         if dir is None:
    260             cur = None
    261         else:
    262             cur = os.getcwd()
    263             os.chdir(dir)
    264290        import subprocess
    265291        with open(os.devnull, 'w') as dev_null:
    266             if subprocess.call(['python', '-Werror', '-c', ''], stdout=dev_null, stderr=dev_null) != 0:
    267                 raise RuntimeError("refusing to run doctests from the current "\
    268                       "directory '{}' since untrusted users could put files in "\
    269                       "this directory, making it unsafe to run Sage code from"\
     292            if subprocess.call(['python', '-Werror', '-c', ''],
     293                    stdout=dev_null, stderr=dev_null, cwd=dir) != 0:
     294                raise RuntimeError(
     295                      "refusing to run doctests from the current "
     296                      "directory '{}' since untrusted users could put files in "
     297                      "this directory, making it unsafe to run Sage code from"
    270298                      .format(os.getcwd()))
    271         if cur is not None:
    272             os.chdir(cur)
    273299
    274300    def create_run_id(self):
    275301        """
     
    301327            sage: DC = DocTestController(DD, [])
    302328            sage: DC.add_files()
    303329            Doctesting entire Sage library.
    304             sage: br = os.readlink(os.path.join(os.environ['SAGE_ROOT'], 'devel', 'sage'))
    305             sage: os.path.join(os.environ['SAGE_ROOT'], 'devel', br, 'sage') in DC.files
     330            sage: os.path.join(os.environ['SAGE_ROOT'], 'devel', 'sage', 'sage') in DC.files
    306331            True
    307332
    308333        ::
     
    325350        """
    326351        opj = os.path.join
    327352        SAGE_ROOT = os.environ['SAGE_ROOT']
    328         br = os.readlink(opj(SAGE_ROOT, 'devel', 'sage'))
    329         base = opj(SAGE_ROOT, 'devel', br)
     353        base = opj(SAGE_ROOT, 'devel', 'sage')
    330354        if self.options.all:
    331355            self.log("Doctesting entire Sage library.")
    332             self.files.extend([opj(base, a) for a in [opj('doc', 'common'), opj('doc', '[a-z][a-z]'), 'sage']])
     356            from glob import glob
     357            self.files.append(opj(base, 'sage'))
     358            self.files.append(opj(base, 'doc', 'common'))
     359            self.files.extend(glob(opj(base, 'doc', '[a-z][a-z]')))
    333360            self.options.sagenb = True
    334361        elif self.options.new:
    335362            self.log("Doctesting files changed since last HG commit.")
     
    351378
    352379    def expand_files_into_sources(self):
    353380        """
    354         Expands ``self.files``, which may include directories, into a list of :class:sage.doctest.FileDocTestSource
     381        Expands ``self.files``, which may include directories, into a
     382        list of :class:sage.doctest.FileDocTestSource
    355383
    356384        This function also handles the optional command line option.
    357385
     
    360388            sage: from sage.doctest.control import DocTestDefaults, DocTestController
    361389            sage: import os
    362390            sage: dirname = os.path.join(os.environ['SAGE_ROOT'], 'devel', 'sage', 'sage', 'doctest')
    363             sage: DD = DocTestDefaults(); DD.optional = 'all'
     391            sage: DD = DocTestDefaults(optional='all')
    364392            sage: DC = DocTestController(DD, [dirname])
    365393            sage: DC.expand_files_into_sources()
    366394            sage: len(DC.sources)
     
    370398
    371399        ::
    372400
    373             sage: DD = DocTestDefaults(); DD.optional = 'magma,guava'
     401            sage: DD = DocTestDefaults(optional='magma,guava')
    374402            sage: DC = DocTestController(DD, [dirname])
    375403            sage: DC.expand_files_into_sources()
    376404            sage: sorted(list(DC.sources[0].optional))
    377405            ['guava', 'magma']
    378406        """
    379407        def skipdir(dirname):
    380             return os.path.exists(os.path.join(dirname, "nodoctest.py")) or dirname[0] == '.'
     408            if os.path.exists(os.path.join(dirname, "nodoctest.py")):
     409                return True
     410            # Workaround for https://github.com/sagemath/sagenb/pull/84
     411            if dirname.endswith(os.path.join(os.sep, 'sagenb', 'data')):
     412                return True
     413            return False
    381414        def skipfile(filename):
    382415            base, ext = os.path.splitext(filename)
    383             if not os.path.exists(filename) or ext not in ('.py', '.pyx', '.pxi', '.sage', '.spyx', '.rst', '.tex'):
     416            if ext not in ('.py', '.pyx', '.pxi', '.sage', '.spyx', '.rst', '.tex'):
    384417                return True
    385418            with open(filename) as F:
    386419                return 'nodoctest' in F.read(50)
    387420        def expand():
    388             for pattern in self.files:
    389                 real_files = glob.glob(pattern)
    390                 if len(real_files) == 0:
    391                     self.log("No files matching %s"%(pattern))
    392                 for path in real_files:
    393                     if os.path.isdir(path):
    394                         for root, dirs, files in os.walk(path):
    395                             for dir in list(dirs):
    396                                 if skipdir(os.path.join(root,dir)):
    397                                     dirs.remove(dir)
    398                             for file in files:
    399                                 if not skipfile(os.path.join(root,file)):
    400                                     yield os.path.join(root, file)
    401                     else:
    402                         # the user input this file explicitly, so we don't skip it
    403                         yield path
     421            for path in self.files:
     422                if os.path.isdir(path):
     423                    for root, dirs, files in os.walk(path):
     424                        for dir in list(dirs):
     425                            if dir[0] == "." or skipdir(os.path.join(root,dir)):
     426                                dirs.remove(dir)
     427                        for file in files:
     428                            if not skipfile(os.path.join(root,file)):
     429                                yield os.path.join(root, file)
     430                else:
     431                    # the user input this file explicitly, so we don't skip it
     432                    yield path
    404433        if self.options.optional == 'all':
    405434            optionals = True
    406435        else:
     
    415444            sage: from sage.doctest.control import DocTestDefaults, DocTestController
    416445            sage: import os
    417446            sage: dirname = os.path.join(os.environ['SAGE_ROOT'], 'devel', 'sage', 'sage', 'doctest')
    418             sage: DD = DocTestDefaults(); DD.failed = True
     447            sage: DD = DocTestDefaults(failed=True)
    419448            sage: DC = DocTestController(DD, [dirname])
    420449            sage: DC.expand_files_into_sources()
    421450            sage: for i, source in enumerate(DC.sources):
     
    436465
    437466    def sort_sources(self):
    438467        """
    439         This function sorts the sources so that slower doctests ar run first.
     468        This function sorts the sources so that slower doctests are run first.
    440469
    441470        EXAMPLES::
    442471
     
    526555                    self.timer = Timer().start()
    527556                    self.dispatcher.dispatch()
    528557                except KeyboardInterrupt:
    529                     # This case only occurs in non-serial mode.
    530                     # We wait a small amount so that the Workers can print which tests were interrupted.
    531                     time.sleep(0.01)
    532558                    it = N - 1
    533559                    break
    534560                finally:
     
    593619
    594620            sage: from sage.doctest.control import DocTestDefaults, DocTestController
    595621            sage: DC = DocTestController(DocTestDefaults(), ["hello_world.py"])
    596             sage: DC._assemble_cmd()
    597             'python .../local/bin/sage-runtests --serial --nthreads 1 --timeout 300 --optional sage --stats_path ... hello_world.py'
     622            sage: print DC._assemble_cmd()
     623            python "$SAGE_LOCAL/bin/sage-runtests" --serial --timeout=300 hello_world.py
    598624        """
    599         cmd = "python %s --serial "%(os.path.join(os.environ["SAGE_ROOT"],"local","bin","sage-runtests"))
    600         opt = self.options.__dict__
     625        cmd = '''python "$SAGE_LOCAL/bin/sage-runtests" --serial '''
     626        opt = dict_difference(self.options.__dict__, DocTestDefaults().__dict__)
    601627        for o in ("all", "sagenb"):
    602             if opt[o]:
     628            if o in opt:
    603629                raise ValueError("You cannot run gdb/valgrind on the whole sage%s library"%("" if o == "all" else "nb"))
    604630        for o in ("all", "sagenb", "long", "force_lib", "verbose", "failed", "new"):
    605             if opt[o]:
     631            if o in opt:
    606632                cmd += "--%s "%o
    607         for o in ("nthreads", "timeout", "optional", "randorder", "stats_path"):
    608             if opt[o]:
    609                 cmd += "--%s %s "%(o, opt[o])
     633        for o in ("timeout", "optional", "randorder", "stats_path"):
     634            if o in opt:
     635                cmd += "--%s=%s "%(o, opt[o])
    610636        return cmd + " ".join(self.files)
    611637
    612638    def run_val_gdb(self, testing=False):
     
    618644        - ``testing`` -- boolean; if True then the command to be run
    619645          will be printed rather than a subprocess started.
    620646
    621         EXAMPLES::
     647        EXAMPLES:
     648
     649        Note that the command lines include unexpanded environment
     650        variables. It is safer to let the shell expand them than to
     651        expand them here and risk insufficient quoting. ::
    622652
    623653            sage: from sage.doctest.control import DocTestDefaults, DocTestController
    624             sage: DD = DocTestDefaults()
    625             sage: DD.gdb = True
     654            sage: DD = DocTestDefaults(gdb=True)
    626655            sage: DC = DocTestController(DD, ["hello_world.py"])
    627656            sage: DC.run_val_gdb(testing=True)
    628             gdb -x .../local/bin/sage-gdb-commands --args python .../local/bin/sage-runtests --serial --nthreads 1 --timeout 1048576 --optional sage --stats_path ... hello_world.py
    629             sage: DD.gdb, DD.valgrind = False, True
     657            exec gdb -x "$SAGE_LOCAL/bin/sage-gdb-commands" --args python "$SAGE_LOCAL/bin/sage-runtests" --serial --timeout=0 hello_world.py
     658
     659        ::
     660
     661            sage: DD = DocTestDefaults(valgrind=True, optional="all")
    630662            sage: DC = DocTestController(DD, ["hello_world.py"])
    631663            sage: DC.run_val_gdb(testing=True)
    632             valgrind --tool=memcheck --leak-resolution=high --log-file=.../sage-memcheck.%p --leak-check=full --num-callers=25 --suppressions=.../local/lib/valgrind/sage.supp python .../local/bin/sage-runtests --serial --nthreads 1 --timeout 1048576 --optional sage --stats_path ... hello_world.py
     664            exec valgrind --tool=memcheck --leak-resolution=high --leak-check=full --num-callers=25 --suppressions="$SAGE_LOCAL/lib/valgrind/sage.supp"  --log-file=".../valgrind/sage-memcheck.%p" python "$SAGE_LOCAL/bin/sage-runtests" --serial --timeout=172800 --optional=all hello_world.py
    633665        """
    634666        try:
    635667            sage_cmd = self._assemble_cmd()
     
    638670            return 2
    639671        opt = self.options
    640672        if opt.gdb:
    641             sageroot = os.environ["SAGE_ROOT"]
    642             cmd = "gdb -x %s --args "%(os.path.join(sageroot,"local","bin","sage-gdb-commands"))
     673            cmd = '''exec gdb -x "$SAGE_LOCAL/bin/sage-gdb-commands" --args '''
    643674            flags = ""
    644675            if opt.logfile:
    645676                sage_cmd += " --logfile %s"%(opt.logfile)
    646677        else:
    647678            if opt.logfile is None:
    648                 dotsage = os.environ["DOT_SAGE"]
    649                 default_log = os.path.join(dotsage, "valgrind")
     679                default_log = os.path.join(DOT_SAGE, "valgrind")
    650680                if os.path.exists(default_log):
    651681                    if not os.path.isdir(default_log):
    652682                        self.log("%s must be a directory"%default_log)
     
    656686                logfile = os.path.join(default_log, "sage-%s")
    657687            else:
    658688                logfile = opt.logfile
    659             logfile = "--log-file=" + logfile
    660689            if opt.valgrind:
    661690                toolname = "memcheck"
    662691                flags = os.getenv("SAGE_MEMCHECK_FLAGS")
    663692                if flags is None:
    664                     suppfile = os.path.join(os.getenv("SAGE_LOCAL"), "lib", "valgrind", "sage.supp")
    665                     flags = "--leak-resolution=high %s --leak-check=full --num-callers=25 --suppressions=%s"%(logfile, suppfile)
     693                    flags = "--leak-resolution=high --leak-check=full --num-callers=25 "
     694                    flags += '''--suppressions="$SAGE_LOCAL/lib/valgrind/sage.supp" '''
    666695            elif opt.massif:
    667696                toolname = "massif"
    668                 flags = os.getenv("SAGE_MASSIF_FLAGS", "--depth=6 %s"%logfile)
     697                flags = os.getenv("SAGE_MASSIF_FLAGS", "--depth=6 ")
    669698            elif opt.cachegrind:
    670699                toolname = "cachegrind"
    671                 flags = os.getenv("SAGE_CACHEGRIND_FLAGS", logfile)
     700                flags = os.getenv("SAGE_CACHEGRIND_FLAGS", "")
    672701            elif opt.omega:
    673702                toolname = "exp-omega"
    674                 flags = os.getenv("SAGE_OMEGA_FLAGS", logfile)
    675             cmd = "valgrind --tool=%s "%(toolname)
     703                flags = os.getenv("SAGE_OMEGA_FLAGS", "")
     704            cmd = "exec valgrind --tool=%s "%(toolname)
     705            flags += ''' --log-file="%s" ''' % logfile
    676706            if opt.omega:
    677707                toolname = "omega"
    678708            if "%s" in flags:
    679709                flags %= toolname + ".%p" # replace %s with toolname
    680             flags += " "
    681710        cmd += flags + sage_cmd
     711
    682712        self.log(cmd)
    683         if not testing:
    684             tm = time.time()
    685             import subprocess
    686             proc = subprocess.Popen(cmd, shell=True)
    687             while time.time()-tm <= opt.timeout and proc.poll() is None:
    688                 time.sleep(0.1)
    689             if time.time() - tm >= opt.timeout:
    690                 os.kill(proc.pid, 9)
    691                 self.log("*** *** Error: TIMED OUT! PROCESS KILLED! *** ***")
    692             return proc.poll()
     713        sys.stdout.flush()
     714        sys.stderr.flush()
     715        if self.logfile is not None:
     716            self.logfile.flush()
    693717
     718        if testing:
     719            return
     720
     721        import signal, subprocess
     722        def handle_alrm(sig, frame):
     723            raise RuntimeError
     724        signal.signal(signal.SIGALRM, handle_alrm)
     725        p = subprocess.Popen(cmd, shell=True)
     726        if opt.timeout > 0:
     727            signal.alarm(opt.timeout)
     728        try:
     729            return p.wait()
     730        except RuntimeError:
     731            self.log("    Time out")
     732            return 4
     733        except KeyboardInterrupt:
     734            self.log("    Interrupted")
     735            return 128
     736        finally:
     737            signal.signal(signal.SIGALRM, signal.SIG_IGN)
     738            if p.returncode is None:
     739                p.terminate()
     740           
    694741    def run(self):
    695742        """
    696743        This function is called after initialization to set up and run all doctests.
     
    732779            self.run_doctests()
    733780            return self.reporter.error_status
    734781
    735 def run_doctests(module, options = None):
     782def run_doctests(module, options=None):
    736783    """
    737784    Runs the doctests in a given file.
    738785
  • sage/doctest/forker.py

    diff --git a/sage/doctest/forker.py b/sage/doctest/forker.py
    a b  
    2121#       Copyright (C) 2012 David Roe <roed.math@gmail.com>
    2222#                          Robert Bradshaw <robertwb@gmail.com>
    2323#                          William Stein <wstein@gmail.com>
     24#       Copyright (C) 2013 Jeroen Demeyer <jdemeyer@cage.ugent.be>
    2425#
    2526#  Distributed under the terms of the GNU General Public License (GPL)
    26 #
     27#  as published by the Free Software Foundation; either version 2 of
     28#  the License, or (at your option) any later version.
    2729#                  http://www.gnu.org/licenses/
    2830#*****************************************************************************
    2931
    30 import hashlib, multiprocessing, os, sys, time, warnings, signal, subprocess, linecache
    31 from collections import defaultdict
    32 import doctest, pdb, traceback
    33 from Queue import Empty
     32from __future__ import print_function
     33
     34import hashlib, multiprocessing, os, sys, time, warnings, signal, linecache
     35import doctest, traceback
    3436import sage.misc.randstate as randstate
    3537from util import Timer, RecordingDict, count_noun
    3638from sources import DictAsObject
    37 from StringIO import StringIO
    3839from parsing import OriginalSource, reduce_hex
    3940from sage.structure.sage_object import SageObject
    4041from parsing import SageOutputChecker, pre_hash, get_source
    41 from sage.misc.misc import walltime
    4242
    43 ################
    44 from sage.structure.sage_object import dumps, loads
    45 ################
    46 
    47 debug_semaphore = None
    48 output_semaphore = None
    4943
    5044def init_sage():
    5145    """
     
    6559    """
    6660    # Do this once before forking.
    6761    import sage.all_cmdline
    68     sage.plot.plot; sage.plot.plot.DOCTEST_MODE=True
     62    sage.plot.plot.DOCTEST_MODE=True
    6963    sage.interfaces.quit.invalidate_all()
    7064    import sage.misc.displayhook
    7165    sys.displayhook = sage.misc.displayhook.DisplayHook(sys.displayhook)
    7266
     67    # Do this *before* forking, because importing readline from a
     68    # child process can screw up the terminal.
     69    import readline
     70
     71    # Workaround for https://github.com/sagemath/sagenb/pull/84
     72    import sagenb.notebook.misc
     73
    7374def warning_function(file):
    7475    """
    7576    Creates a function that prints warnings to the given file.
     
    100101            pass # the file (probably stdout) is invalid
    101102    return doctest_showwarning
    102103
    103 def _test_activate_stdin():
     104
     105class SageSpoofInOut(SageObject):
    104106    """
    105     This function is designed to test
    106     :meth:`SageSpoofOut.activate_stdin` and
    107     :meth:`SageSpoofOut.deactivate_stdin`.
     107    We replace the standard :class:`doctest._SpoofOut` for three reasons:
    108108
    109     TESTS::
     109    - we need to divert the output of C programs that don't print
     110      through sys.stdout,
     111    - we want the ability to recover partial output from doctest
     112      processes that segfault.
     113    - we also redirect stdin (usually from /dev/null) during doctests.
    110114
    111         sage: import os
    112         sage: os.environ['SAGE_PEXPECT_LOG'] = "1"
    113         sage: sage0.quit()
    114         sage: _ = sage0.eval("from sage.doctest.forker import _test_activate_stdin")
    115         sage: sage0._prompt = "my_prompt: "
    116         sage: print sage0.eval("_test_activate_stdin()")
    117         bad_input: input not available before activation
    118         sage: sage0._prompt = "sage: "
    119         sage: print sage0.eval("input active")
    120         input received: input active
    121         bad_input: input not available after deactivation
    122     """
    123     O = os.tmpfile()
    124     save_stdin = sys.stdin
    125     sys.stdin = open(os.devnull)
    126     v = None
    127     try:
    128         S = SageSpoofOut(O)
    129         try:
    130             w = raw_input("bad_input: ")
    131         except EOFError:
    132             print "input not available before activation"
    133         S.activate_stdin()
    134         v = raw_input("my_prompt: ")
    135     finally:
    136         print "input received:", v
    137         S.deactivate_stdin()
    138         try:
    139             w = raw_input("bad_input: ")
    140         except EOFError:
    141             print "input not available after deactivation"
    142         sys.stdin = save_stdin
    143 
    144 class SageSpoofOut(SageObject):
    145     """
    146     We replace the standard :class:`doctest._SpoofOut` for two reasons:
    147 
    148     - we need to divert the output of C programs that don't print through sys.stdout,
    149     - we want the ability to recover partial output from doctest processes that segfault.
     115    This class defines streams ``self.real_stdin``, ``self.real_stdout``
     116    and ``self.real_stderr`` which refer to the original streams.
    150117
    151118    INPUT:
    152119
    153     - ``outfile`` -- an open file handle (usually from os.tmpfile) to which stdout should be redirected.
     120    - ``outfile`` -- (default: ``os.tmpfile()``) a seekable open file
     121     object to which stdout and stderr should be redirected.
     122
     123    - ``infile`` -- (default: ``open(os.devnull)``) an open file object
     124      from which stdin should be redirected.
    154125
    155126    EXAMPLES::
    156127
    157         sage: import os
    158         sage: from sage.doctest.forker import SageSpoofOut
     128        sage: import os, subprocess
     129        sage: from sage.doctest.forker import SageSpoofInOut
    159130        sage: O = os.tmpfile()
    160         sage: S = SageSpoofOut(O)
     131        sage: S = SageSpoofInOut(O)
    161132        sage: try:
    162133        ....:     S.start_spoofing()
    163134        ....:     print "hello world"
     
    166137        ....:
    167138        sage: S.getvalue()
    168139        'hello world\n'
     140        sage: O.seek(0)
     141        sage: S = SageSpoofInOut(outfile=sys.stdout, infile=O)
     142        sage: try:
     143        ....:     S.start_spoofing()
     144        ....:     _ = subprocess.check_call("cat")
     145        ....: finally:
     146        ....:     S.stop_spoofing()
     147        ....:
     148        hello world
    169149    """
    170     def __init__(self, outfile):
     150    def __init__(self, outfile=None, infile=None):
    171151        """
    172152        Initialization.
    173153
    174154        TESTS::
    175155
    176             sage: import os
    177             sage: from sage.doctest.forker import SageSpoofOut
    178             sage: SageSpoofOut(os.tmpfile())
    179             <class 'sage.doctest.forker.SageSpoofOut'>
     156            sage: from sage.doctest.forker import SageSpoofInOut
     157            sage: SageSpoofInOut(os.tmpfile(), os.tmpfile())
     158            <class 'sage.doctest.forker.SageSpoofInOut'>
    180159        """
    181         self.outfile = outfile
     160        if infile is None:
     161            self.infile = open(os.devnull)
     162        else:
     163            self.infile = infile
     164        if outfile is None:
     165            self.outfile = os.tmpfile()
     166        else:
     167            self.outfile = outfile
    182168        self.spoofing = False
    183         self.stdin_active = False #(sys.stdin.fileno() == 0)
    184         #self.stdin_active_original = self.stdin_active
    185         self.dup_stdout = os.dup(sys.stdout.fileno())
    186         self.dup_stderr = os.dup(sys.stderr.fileno())
    187         self.dup_stdin = os.dup(sys.stdin.fileno())
     169        self.real_stdin = os.fdopen(os.dup(sys.stdin.fileno()), "r")
     170        self.real_stdout = os.fdopen(os.dup(sys.stdout.fileno()), "w")
     171        self.real_stderr = os.fdopen(os.dup(sys.stderr.fileno()), "w")
    188172        self.position = 0
    189173
    190     def fileno(self):
     174    def __del__(self):
    191175        """
    192         This object serves as stdout in various places, so we need to
    193         emulate stdout's fileno in order to be able to recurse.
     176        Stop spoofing.
     177
     178        TESTS::
     179
     180            sage: from sage.doctest.forker import SageSpoofInOut
     181            sage: spoof = SageSpoofInOut()
     182            sage: spoof.start_spoofing()
     183            sage: print "Spoofed!"  # No output
     184            sage: del spoof
     185            sage: print "Not spoofed!"
     186            Not spoofed!
     187        """
     188        self.stop_spoofing()
     189
     190    def start_spoofing(self):
     191        """
     192        Set stdin to read from ``self.infile`` and stdout to print to
     193        ``self.outfile``.
    194194
    195195        EXAMPLES::
    196196
    197197            sage: import os
    198             sage: from sage.doctest.forker import SageSpoofOut
     198            sage: from sage.doctest.forker import SageSpoofInOut
    199199            sage: O = os.tmpfile()
    200             sage: S = SageSpoofOut(O)
    201             sage: S.fileno() == 1
    202             True
    203         """
    204         return sys.stdout.fileno()
    205 
    206     def start_spoofing(self):
    207         """
    208         Set stdout to print to outfile.
    209 
    210         EXAMPLES::
    211 
    212             sage: import os
    213             sage: from sage.doctest.forker import SageSpoofOut
    214             sage: O = os.tmpfile()
    215             sage: S = SageSpoofOut(O)
     200            sage: S = SageSpoofInOut(O)
    216201            sage: try:
    217202            ....:     S.start_spoofing()
    218203            ....:     print "this is not printed"
     
    221206            ....:
    222207            sage: S.getvalue()
    223208            'this is not printed\n'
     209            sage: O.seek(0)
     210            sage: S = SageSpoofInOut(infile=O)
     211            sage: try:
     212            ....:     S.start_spoofing()
     213            ....:     v = sys.stdin.read()
     214            ....: finally:
     215            ....:     S.stop_spoofing()
     216            ....:
     217            sage: v
     218            'this is not printed\n'
    224219
    225         We also catch C output::
     220        We also catch non-Python output::
    226221
    227222            sage: try:
    228223            ....:     S.start_spoofing()
     
    235230        """
    236231        if not self.spoofing:
    237232            sys.stdout.flush()
     233            sys.stderr.flush()
     234            self.outfile.flush()
     235            os.dup2(self.infile.fileno(), sys.stdin.fileno())
    238236            os.dup2(self.outfile.fileno(), sys.stdout.fileno())
    239             sys.stderr.flush()
    240237            os.dup2(self.outfile.fileno(), sys.stderr.fileno())
    241238            self.spoofing = True
    242239
    243240    def stop_spoofing(self):
    244241        """
    245         Reset stdout to its original value.
     242        Reset stdin and stdout to their original values.
    246243
    247244        EXAMPLES::
    248245
    249             sage: import os
    250             sage: from sage.doctest.forker import SageSpoofOut
    251             sage: O = os.tmpfile()
    252             sage: S = SageSpoofOut(O)
     246            sage: from sage.doctest.forker import SageSpoofInOut
     247            sage: S = SageSpoofInOut()
    253248            sage: try:
    254249            ....:     S.start_spoofing()
    255250            ....:     print "this is not printed"
     
    261256        """
    262257        if self.spoofing:
    263258            sys.stdout.flush()
    264             os.dup2(self.dup_stdout, sys.stdout.fileno())
    265259            sys.stderr.flush()
    266             os.dup2(self.dup_stderr, sys.stderr.fileno())
     260            self.real_stdout.flush()
     261            self.real_stderr.flush()
     262            os.dup2(self.real_stdin.fileno(), sys.stdin.fileno())
     263            os.dup2(self.real_stdout.fileno(), sys.stdout.fileno())
     264            os.dup2(self.real_stderr.fileno(), sys.stderr.fileno())
    267265            self.spoofing = False
    268266
    269267    def getvalue(self):
    270268        """
    271         Gets the value that has been printed to the outfile since the last time this function was called.
     269        Gets the value that has been printed to ``outfile`` since the
     270        last time this function was called.
    272271
    273272        EXAMPLES::
    274273
    275             sage: import os
    276             sage: from sage.doctest.forker import SageSpoofOut
    277             sage: O = os.tmpfile()
    278             sage: S = SageSpoofOut(O)
     274            sage: from sage.doctest.forker import SageSpoofInOut
     275            sage: S = SageSpoofInOut()
    279276            sage: try:
    280277            ....:     S.start_spoofing()
    281278            ....:     print "step 1"
     
    301298            result += "\n"
    302299        return result
    303300
    304     def write(self, a):
    305         """
    306         When debugging we need to pretend this object is stdout.
    307 
    308         EXAMPLES::
    309 
    310             sage: import os
    311             sage: from sage.doctest.forker import SageSpoofOut
    312             sage: O = os.tmpfile()
    313             sage: S = SageSpoofOut(O)
    314             sage: try:
    315             ....:     S.start_spoofing()
    316             ....:     S.write("this is not printed\n")
    317             ....: finally:
    318             ....:     S.stop_spoofing()
    319             ....:
    320             sage: S.getvalue()
    321             'this is not printed\n'
    322         """
    323         sys.stdout.write(a)
    324         sys.stdout.flush()
    325 
    326     def unspoofed_write(self, a):
    327         """
    328         Prints to the unspoofed standard out.
    329 
    330         EXAMPLES::
    331 
    332             sage: import os
    333             sage: from sage.doctest.forker import SageSpoofOut
    334             sage: O = os.tmpfile()
    335             sage: S = SageSpoofOut(O)
    336             sage: try:
    337             ....:     S.start_spoofing()
    338             ....:     print "spoofed"
    339             ....:     S.unspoofed_write("unspoofed\n")
    340             ....: finally:
    341             ....:     S.stop_spoofing()
    342             ....:
    343             unspoofed
    344             sage: S.getvalue()
    345             'spoofed\n'
    346         """
    347         spoofed = self.spoofing
    348         try:
    349             if output_semaphore is not None:
    350                 output_semaphore.acquire()
    351             if spoofed:
    352                 self.stop_spoofing()
    353             sys.stdout.write(a)
    354         finally:
    355             sys.stdout.flush()
    356             if spoofed:
    357                 self.start_spoofing()
    358             if output_semaphore is not None:
    359                 output_semaphore.release()
    360 
    361     def activate_stdin(self):
    362         """
    363         Turns on stdin, which is useful when user input is needed in a subprocess.
    364 
    365         TESTS::
    366 
    367             sage: import os
    368             sage: os.environ['SAGE_PEXPECT_LOG'] = "1"
    369             sage: sage0.quit()
    370             sage: _ = sage0.eval("from sage.doctest.forker import _test_activate_stdin")
    371             sage: sage0._prompt = "my_prompt: "
    372             sage: print sage0.eval("_test_activate_stdin()")
    373             bad_input: input not available before activation
    374             sage: sage0._prompt = "sage: "
    375             sage: print sage0.eval("input active") # indirect doctest
    376             input received: input active
    377             bad_input: input not available after deactivation
    378         """
    379         if not self.stdin_active:
    380             os.dup2(0, sys.stdin.fileno())
    381             self.stdin_active = True
    382 
    383     def deactivate_stdin(self):
    384         """
    385         Restores stdin to its original state (which ignores user input
    386         if this function is being called in a subprocess).
    387 
    388         TESTS::
    389 
    390             sage: import os
    391             sage: os.environ['SAGE_PEXPECT_LOG'] = "1"
    392             sage: sage0.quit()
    393             sage: _ = sage0.eval("from sage.doctest.forker import _test_activate_stdin")
    394             sage: sage0._prompt = "my_prompt: "
    395             sage: print sage0.eval("_test_activate_stdin()")
    396             bad_input: input not available before activation
    397             sage: sage0._prompt = "sage: "
    398             sage: print sage0.eval("input active") # indirect doctest
    399             input received: input active
    400             bad_input: input not available after deactivation
    401         """
    402         if self.stdin_active:
    403             os.dup2(self.dup_stdin, sys.stdin.fileno())
    404             self.stdin_active = False
    405 
    406 class SagePdb(doctest._OutputRedirectingPdb):
    407     """
    408     We subclass :class:`doctest._OutputRedirectingPdb` since switching
    409     in and out of spoofing can't be done just be assigning to
    410     sys.stdout.
    411 
    412     INPUT:
    413 
    414     - ``fakeout`` -- a :class:`SageSpoofOut` instance
    415 
    416     EXAMPLES::
    417 
    418         sage: from sage.doctest.forker import SageSpoofOut, SagePdb
    419         sage: import os; O = os.tmpfile()
    420         sage: S = SageSpoofOut(O)
    421         sage: SagePdb(S)
    422         <sage.doctest.forker.SagePdb instance at ...>
    423     """
    424     def __init__(self, fakeout):
    425         """
    426         Initialization.
    427 
    428         TESTS::
    429 
    430             sage: from sage.doctest.forker import SageSpoofOut, SagePdb
    431             sage: import os; O = os.tmpfile()
    432             sage: S = SageSpoofOut(O)
    433             sage: SagePdb(S).use_rawinput
    434             1
    435         """
    436         self._fakeout = fakeout
    437         doctest._OutputRedirectingPdb.__init__(self, fakeout)
    438 
    439     def trace_dispatch(self, *args):
    440         """
    441         We stop spoofing before calling :meth:`pdb.Pdb.trace_dispatch` and start again afterward.
    442 
    443         TESTS::
    444 
    445             sage: import os
    446             sage: os.environ['SAGE_PEXPECT_LOG'] = "1"
    447             sage: sage0.quit()
    448             sage: _ = sage0.eval("import doctest, sys, os, multiprocessing, subprocess")
    449             sage: _ = sage0.eval("from sage.doctest.parsing import SageOutputChecker")
    450             sage: _ = sage0.eval("import sage.doctest.forker as sdf")
    451             sage: _ = sage0.eval("from sage.doctest.control import DocTestDefaults; DD = DocTestDefaults()")
    452             sage: _ = sage0.eval("ex = doctest.Example('E = EllipticCurve([0,0]); E', 'A singular Elliptic Curve')")
    453             sage: _ = sage0.eval("DT = doctest.DocTest([ex], globals(), 'singular_curve', None, 0, None)")
    454             sage: _ = sage0.eval("DTR = sdf.SageDocTestRunner(SageOutputChecker(), output = os.tmpfile(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)")
    455             sage: _ = sage0.eval("sdf.debug_semaphore = multiprocessing.Semaphore()")
    456             sage: _ = sage0.eval("sdf.output_semaphore = multiprocessing.Semaphore()")
    457             sage: sage0._prompt = r"\(Pdb\) "
    458             sage: sage0.eval("DTR.run(DT, clear_globs=False)") # indirect doctest
    459             '... "Invariants %s define a singular curve."%ainvs'
    460             sage: sage0._prompt = "sage: "
    461             sage: tb = sage0.eval("quit")
    462         """
    463         if self._fakeout.spoofing:
    464             self._fakeout.stop_spoofing()
    465             try:
    466                 return pdb.Pdb.trace_dispatch(self, *args)
    467             finally:
    468                 self._fakeout.start_spoofing()
    469         else:
    470             return pdb.Pdb.trace_dispatch(self, *args)
    471301
    472302class SageDocTestRunner(doctest.DocTestRunner):
    473303    def __init__(self, *args, **kwds):
    474304        """
    475         A customized version of DocTestRunner that tracs dependencies of doctests.
     305        A customized version of DocTestRunner that tracks dependencies
     306        of doctests.
    476307
    477308        INPUT:
    478309
     
    493324            sage: from sage.doctest.forker import SageDocTestRunner
    494325            sage: from sage.doctest.control import DocTestDefaults; DD = DocTestDefaults()
    495326            sage: import doctest, sys, os
    496             sage: DTR = SageDocTestRunner(SageOutputChecker(), output = os.tmpfile(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
     327            sage: DTR = SageDocTestRunner(SageOutputChecker(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
    497328            sage: DTR
    498329            <sage.doctest.forker.SageDocTestRunner instance at ...>
    499330        """
    500         O = kwds.pop('output')
     331        O = kwds.pop('outtmpfile', None)
     332        self.msgfile = kwds.pop('msgfile', None)
    501333        self.options = kwds.pop('sage_options')
    502334        doctest.DocTestRunner.__init__(self, *args, **kwds)
    503         self._fakeout = SageSpoofOut(O)
     335        self._fakeout = SageSpoofInOut(O)
     336        if self.msgfile is None:
     337            self.msgfile = self._fakeout.real_stdout
    504338        self.history = []
    505339        self.references = []
    506340        self.setters = {}
    507341        self.running_global_digest = hashlib.md5()
    508         self.delayed_output = []
    509342
    510343    def _run(self, test, compileflags, out):
    511344        """
     
    521354          :class:`SageWorker`.
    522355
    523356        Since it needs to be able to read stdout, it should be called
    524         while spoofing using :class:`SageSpoofOut`.
     357        while spoofing using :class:`SageSpoofInOut`.
    525358
    526359        EXAMPLES::
    527360
     
    530363            sage: from sage.doctest.sources import FileDocTestSource
    531364            sage: from sage.doctest.control import DocTestDefaults; DD = DocTestDefaults()
    532365            sage: import doctest, sys, os
    533             sage: DTR = SageDocTestRunner(SageOutputChecker(), output = os.tmpfile(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
     366            sage: DTR = SageDocTestRunner(SageOutputChecker(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
    534367            sage: filename = os.path.join(os.environ['SAGE_ROOT'],'devel','sage','sage','doctest','forker.py')
    535368            sage: FDS = FileDocTestSource(filename,True,False,set(['sage']),None)
    536369            sage: doctests, extras = FDS.create_doctests(globals())
     
    572405            # Record that we started this example.
    573406            tries += 1
    574407            # We print the example we're running for easier debugging
    575             # if this file times out or sefaults.
     408            # if this file times out or crashes.
    576409            with OriginalSource(example):
    577                 print "sage: " + example.source[:-1] + " ## line %s ##"%(test.lineno + example.lineno + 1)
     410                print("sage: " + example.source[:-1] + " ## line %s ##"%(test.lineno + example.lineno + 1))
    578411            # Update the position so that result comparison works
    579412            throwaway = self._fakeout.getvalue()
    580413            if not quiet:
    581414                self.report_start(out, test, example)
    582415
     416            # Flush files before running the example, so we know for
     417            # sure that everything is reported properly if the test
     418            # crashes.
     419            sys.stdout.flush()
     420            sys.stderr.flush()
     421            self.msgfile.flush()
     422
    583423            # Use a special filename for compile(), so we can retrieve
    584424            # the source code during interactive debugging (see
    585425            # __patched_linecache_getlines).
    586426            filename = '<doctest %s[%d]>' % (test.name, examplenum)
    587427
    588428            # Run the example in the given context (globs), and record
    589             # any exception that gets raised.  (But don't intercept
    590             # keyboard interrupts.)
     429            # any exception that gets raised. But for SystemExit, we
     430            # simply propagate the exception.
     431            exception = None
    591432            try:
    592433                # Don't blink!  This is where the user's code gets run.
    593434                compiled = compile(example.source, filename, "single",
    594435                             compileflags, 1)
    595436                self.execute(example, compiled, test.globs)
    596                 self.debugger.set_continue() # ==== Example Finished ====
    597                 exception = None
    598             except KeyboardInterrupt:
    599                 # We check to see if it's expected
     437            except SystemExit:
     438                raise
     439            except BaseException:
    600440                exception = sys.exc_info()
    601                 exc_msg = traceback.format_exception_only(*exception[:2])[-1]
    602                 if example.exc_msg is None or not check(example.exc_msg, exc_msg, self.optionflags):
    603                     raise
    604                 else:
    605                     # KeyboardInterrupt was expected
    606                     self.debugger.set_continue()
    607             except Exception:
    608                 exception = sys.exc_info()
    609                 self.debugger.set_continue() # ==== Example Finished ====
     441            finally:
     442                if self.debugger is not None:
     443                    self.debugger.set_continue() # ==== Example Finished ====
    610444
    611445            got = self._fakeout.getvalue()  # the actual output
    612446            outcome = FAILURE   # guilty until proved innocent or insane
     
    617451                if check(example.want, got, self.optionflags):
    618452                    outcome = SUCCESS
    619453
    620             # The example raised an exception:  check if it was expected.
     454            # The example raised an exception: check if it was expected.
    621455            else:
    622456                exc_info = sys.exc_info()
    623457                exc_msg = traceback.format_exception_only(*exc_info[:2])[-1]
     
    629463                if example.exc_msg is None:
    630464                    outcome = BOOM
    631465
    632                 # We expected an exception:  see whether it matches.
     466                # We expected an exception: see whether it matches.
    633467                elif check(example.exc_msg, exc_msg, self.optionflags):
    634468                    outcome = SUCCESS
    635469
     
    643477
    644478            # Report the outcome.
    645479            if outcome is SUCCESS:
    646                 if self.options.warn_long and walltime(self.tmp_time) > self.options.warn_long:
     480                if self.options.warn_long and example.walltime > self.options.warn_long:
    647481                    self.report_overtime(out, test, example, got)
    648482                    failures += 1
    649483                elif not quiet:
     
    672506        Runs the examples in a given doctest.
    673507
    674508        This function replaces :class:`doctest.DocTestRunner.run`
    675         since it needs to handle spoofing and the output redirecting
    676         Pdb differently.  It also leaves the display hook in place.
     509        since it needs to handle spoofing. It also leaves the display
     510        hook in place.
    677511
    678512        INPUT:
    679513
     
    704538            sage: from sage.doctest.sources import FileDocTestSource
    705539            sage: from sage.doctest.control import DocTestDefaults; DD = DocTestDefaults()
    706540            sage: import doctest, sys, os
    707             sage: DTR = SageDocTestRunner(SageOutputChecker(), output = os.tmpfile(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
     541            sage: DTR = SageDocTestRunner(SageOutputChecker(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
    708542            sage: filename = os.path.join(os.environ['SAGE_ROOT'],'devel','sage','sage','doctest','forker.py')
    709543            sage: FDS = FileDocTestSource(filename,True,False,set(['sage']),None)
    710544            sage: doctests, extras = FDS.create_doctests(globals())
     
    718552        self.test = test
    719553        if compileflags is None:
    720554            compileflags = doctest._extract_future_flags(test.globs)
    721         save_set_trace = pdb.set_trace
    722         self.debugger = SagePdb(self._fakeout)
    723         self.debugger.reset()
    724         pdb.set_trace = self.debugger.set_trace
     555        # We use this slightly modified version of Pdb because it
     556        # interacts better with the doctesting framework (like allowing
     557        # doctests for sys.settrace()). Since we already have output
     558        # spoofing in place, there is no need for redirection.
     559        if self.options.debug:
     560            self.debugger = doctest._OutputRedirectingPdb(sys.stdout)
     561            self.debugger.reset()
     562        else:
     563            self.debugger = None
    725564        self.save_linecache_getlines = linecache.getlines
    726565        linecache.getlines = self._DocTestRunner__patched_linecache_getlines
    727         if out is None and (self.options.serial or self.options.verbose or self.options.debug):
    728             out = self._fakeout.unspoofed_write
    729         elif out is None:
     566        if out is None:
    730567            def out(s):
    731                 self.delayed_output.append(s)
     568                self.msgfile.write(s)
    732569
    733570        self._fakeout.start_spoofing()
    734571        # If self.options.initial is set, we show only the first failure in each doctest block.
     
    737574            return self._run(test, compileflags, out)
    738575        finally:
    739576            self._fakeout.stop_spoofing()
    740             pdb.set_trace = save_set_trace
    741577            linecache.getlines = self.save_linecache_getlines
    742578            if clear_globs:
    743579                test.globs.clear()
    744580
    745     def summarize(self, verbose=None, delay_list=None):
     581    def summarize(self, verbose=None):
    746582        """
    747         Returns a string summarizing the results of testing.
    748 
    749         Summarize works a bit differently for Sage testing since we
    750         want to continue delaying output so that it is printed at the
    751         same time as
    752         :meth:`sage.doctest.reporting.DocTestReporter.report`, and we
    753         want to log it.
     583        Print results of testing to ``self.msgfile`` and return number
     584        of failures and tests run.
    754585
    755586        INPUT:
    756587
    757588        - ``verbose`` -- whether to print lots of stuff
    758589
    759         - ``delay_list`` -- either None or a list of strings on which to append delayed output
    760 
    761590        OUTPUT:
    762591
    763         - if ``delay_list`` is None, prints a summary of tests run.
    764           Otherwise, appends lines of the summary to ``delay_list``.
    765 
    766592        - returns ``(f, t)``, a :class:`doctest.TestResults` instance
    767593          giving the number of failures and the total number of tests
    768594          run.
     
    773599            sage: from sage.doctest.forker import SageDocTestRunner
    774600            sage: from sage.doctest.control import DocTestDefaults; DD = DocTestDefaults()
    775601            sage: import doctest, sys, os
    776             sage: DTR = SageDocTestRunner(SageOutputChecker(), output = os.tmpfile(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
    777             sage: DTR.delayed_output = ["A delayed failure\n","And another one\n"]
     602            sage: DTR = SageDocTestRunner(SageOutputChecker(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
    778603            sage: DTR._name2ft['sage.doctest.forker'] = (1,120)
    779             sage: DTR.summarize()
    780             A delayed failure
    781             And another one
     604            sage: results = DTR.summarize()
    782605            **********************************************************************
    783606            1 item had failures:
    784607                1 of 120 in sage.doctest.forker
     608            sage: results
    785609            TestResults(failed=1, attempted=120)
    786610        """
    787611        if verbose is None:
    788612            verbose = self._verbose
    789         print_now = delay_list is None
    790         if delay_list is None:
    791             delay_list = []
    792         delay_list.extend(self.delayed_output)
     613        m = self.msgfile
    793614        notests = []
    794615        passed = []
    795616        failed = []
     
    807628                failed.append(x)
    808629        if verbose:
    809630            if notests:
    810                 delay_list.append(count_noun(len(notests), "item") + " had no tests:\n")
     631                print(count_noun(len(notests), "item") + " had no tests:", file=m)
    811632                notests.sort()
    812633                for thing in notests:
    813                     delay_list.append("    %s\n"%thing)
     634                    print("    %s"%thing, file=m)
    814635            if passed:
    815                 delay_list.append(count_noun(len(passed), "item") + " passed all tests:\n")
     636                print(count_noun(len(passed), "item") + " passed all tests:", file=m)
    816637                passed.sort()
    817638                for thing, count in passed:
    818                     delay_list.append(" %s in %s\n"%(count_noun(count, "test", pad_number=3, pad_noun=True), thing))
     639                    print(" %s in %s"%(count_noun(count, "test", pad_number=3, pad_noun=True), thing), file=m)
    819640        if failed:
    820             delay_list.append(self.DIVIDER + "\n")
    821             delay_list.append(count_noun(len(failed), "item") + " had failures:\n")
     641            print(self.DIVIDER, file=m)
     642            print(count_noun(len(failed), "item") + " had failures:", file=m)
    822643            failed.sort()
    823644            for thing, (f, t) in failed:
    824                 delay_list.append(" %3d of %3d in %s\n"%(f, t, thing))
     645                print(" %3d of %3d in %s"%(f, t, thing), file=m)
    825646        if verbose:
    826             delay_list.append(count_noun(totalt, "test") + " in " + count_noun(len(self._name2ft), "item") + ".\n")
    827             delay_list.append("%s passed and %s failed.\n"%(totalt - totalf, totalf))
     647            print(count_noun(totalt, "test") + " in " + count_noun(len(self._name2ft), "item") + ".", file=m)
     648            print("%s passed and %s failed."%(totalt - totalf, totalf), file=m)
    828649            if totalf:
    829                 delay_list.append("***Test Failed***\n")
     650                print("***Test Failed***", file=m)
    830651            else:
    831                 delay_list.append("Test passed.\n")
    832         if print_now:
    833             delayed_output = "".join(delay_list)
    834             if self.options.logfile is not None:
    835                 try:
    836                     with open(self.options.logfile, 'a') as logger:
    837                         logger.write(delayed_output)
    838                 except IOError:
    839                     pass
    840             sys.stdout.write(delayed_output)
    841             sys.stdout.flush()
     652                print("Test passed.", file=m)
     653        m.flush()
    842654        return doctest.TestResults(totalf, totalt)
    843655
    844656    def update_digests(self, example):
     
    870682            sage: from sage.doctest.sources import FileDocTestSource
    871683            sage: from sage.doctest.control import DocTestDefaults; DD = DocTestDefaults()
    872684            sage: import doctest, sys, os, hashlib
    873             sage: DTR = SageDocTestRunner(SageOutputChecker(), output = os.tmpfile(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
     685            sage: DTR = SageDocTestRunner(SageOutputChecker(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
    874686            sage: filename = os.path.join(os.environ['SAGE_ROOT'],'devel','sage','sage','doctest','forker.py')
    875687            sage: FDS = FileDocTestSource(filename,True,False,set(['sage']),None)
    876688            sage: doctests, extras = FDS.create_doctests(globals())
     
    927739            sage: from sage.doctest.util import RecordingDict
    928740            sage: from sage.doctest.control import DocTestDefaults; DD = DocTestDefaults()
    929741            sage: import doctest, sys, os, hashlib
    930             sage: DTR = SageDocTestRunner(SageOutputChecker(), output = os.tmpfile(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
     742            sage: DTR = SageDocTestRunner(SageOutputChecker(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
    931743            sage: DTR.running_doctest_digest = hashlib.md5()
    932744            sage: filename = os.path.join(os.environ['SAGE_ROOT'],'devel','sage','sage','doctest','forker.py')
    933745            sage: FDS = FileDocTestSource(filename,True,False,set(['sage']),None)
     
    1017829            sage: from sage.doctest.sources import FileDocTestSource
    1018830            sage: from sage.doctest.control import DocTestDefaults; DD = DocTestDefaults()
    1019831            sage: import doctest, sys, os
    1020             sage: DTR = SageDocTestRunner(SageOutputChecker(), output = os.tmpfile(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
     832            sage: DTR = SageDocTestRunner(SageOutputChecker(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
    1021833            sage: filename = os.path.join(os.environ['SAGE_ROOT'],'devel','sage','sage','doctest','forker.py')
    1022834            sage: FDS = FileDocTestSource(filename,True,False,set(['sage']),None)
    1023835            sage: doctests, extras = FDS.create_doctests(globals())
     
    1048860
    1049861        INPUT:
    1050862
    1051         - ``out`` -- a function for printing (delayed or immediate)
     863        - ``out`` -- a function for printing
    1052864
    1053865        - ``test`` -- a :class:`doctest.DocTest` instance
    1054866
     
    1065877            sage: from sage.doctest.sources import FileDocTestSource
    1066878            sage: from sage.doctest.control import DocTestDefaults; DD = DocTestDefaults()
    1067879            sage: import doctest, sys, os
    1068             sage: DTR = SageDocTestRunner(SageOutputChecker(), output = os.tmpfile(), verbose=True, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
     880            sage: DTR = SageDocTestRunner(SageOutputChecker(), verbose=True, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
    1069881            sage: filename = os.path.join(os.environ['SAGE_ROOT'],'devel','sage','sage','doctest','forker.py')
    1070882            sage: FDS = FileDocTestSource(filename,True,False,set(['sage']),None)
    1071883            sage: doctests, extras = FDS.create_doctests(globals())
     
    1085897                else:
    1086898                    start_txt += 'Expecting nothing\n'
    1087899                out(start_txt)
    1088             if self._verbose or self.options.warn_long:
    1089                 self.tmp_time = walltime()
    1090900
    1091901    def report_success(self, out, test, example, got):
    1092902        """
     
    1094904
    1095905        INPUT:
    1096906
    1097         - ``out`` -- a function for printing (delayed or immediate)
     907        - ``out`` -- a function for printing
    1098908
    1099909        - ``test`` -- a :class:`doctest.DocTest` instance
    1100910
     
    1114924            sage: from sage.doctest.control import DocTestDefaults; DD = DocTestDefaults()
    1115925            sage: from sage.misc.misc import walltime
    1116926            sage: import doctest, sys, os
    1117             sage: DTR = SageDocTestRunner(SageOutputChecker(), output = os.tmpfile(), verbose=True, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
    1118             sage: DTR.tmp_time = walltime()
     927            sage: DTR = SageDocTestRunner(SageOutputChecker(), verbose=True, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
    1119928            sage: filename = os.path.join(os.environ['SAGE_ROOT'],'devel','sage','sage','doctest','forker.py')
    1120929            sage: FDS = FileDocTestSource(filename,True,False,set(['sage']),None)
    1121930            sage: doctests, extras = FDS.create_doctests(globals())
    1122931            sage: ex = doctests[0].examples[0]
     932            sage: ex.walltime = 0.0
    1123933            sage: DTR.report_success(sys.stdout.write, doctests[0], ex, '1764')
    1124             ok [...s]
     934            ok [0.00 s]
    1125935        """
    1126936        # We completely replace doctest.DocTestRunner.report_success so that we can include time taken for the test
    1127937        if self._verbose:
    1128             out("ok [%.2f s]\n"%(walltime(self.tmp_time)))
     938            out("ok [%.2f s]\n"%example.walltime)
    1129939
    1130     # We name the local strangely since they get imported into
    1131940    def report_failure(self, out, test, example, got, globs):
    1132941        """
    1133942        Called when a doctest fails.
    1134943
    1135944        INPUT:
    1136945
    1137         - ``out`` -- a function for printing (delayed or immediate)
     946        - ``out`` -- a function for printing
    1138947
    1139948        - ``test`` -- a :class:`doctest.DocTest` instance
    1140949
     
    1148957
    1149958        - prints a report to ``out``
    1150959
    1151         - if in debugging mode, starts an iPython prompt at the point
    1152           of the failure
    1153 
    1154960        EXAMPLES::
    1155961
    1156962            sage: from sage.doctest.parsing import SageOutputChecker
     
    1158964            sage: from sage.doctest.sources import FileDocTestSource
    1159965            sage: from sage.doctest.control import DocTestDefaults; DD = DocTestDefaults()
    1160966            sage: import doctest, sys, os
    1161             sage: DTR = SageDocTestRunner(SageOutputChecker(), output = os.tmpfile(), verbose=True, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
     967            sage: DTR = SageDocTestRunner(SageOutputChecker(), verbose=True, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
    1162968            sage: filename = os.path.join(os.environ['SAGE_ROOT'],'devel','sage','sage','doctest','forker.py')
    1163969            sage: FDS = FileDocTestSource(filename,True,False,set(['sage']),None)
    1164970            sage: doctests, extras = FDS.create_doctests(globals())
     
    1185991
    1186992        INPUT:
    1187993
    1188         - ``out`` -- a function for printing (delayed or immediate)
     994        - ``out`` -- a function for printing
    1189995
    1190996        - ``test`` -- a :class:`doctest.DocTest` instance
    1191997
     
    12051011            sage: from sage.doctest.control import DocTestDefaults; DD = DocTestDefaults()
    12061012            sage: from sage.misc.misc import walltime
    12071013            sage: import doctest, sys, os
    1208             sage: DTR = SageDocTestRunner(SageOutputChecker(), output = os.tmpfile(), verbose=True, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
     1014            sage: DTR = SageDocTestRunner(SageOutputChecker(), verbose=True, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
    12091015            sage: filename = os.path.join(os.environ['SAGE_ROOT'],'devel','sage','sage','doctest','forker.py')
    12101016            sage: FDS = FileDocTestSource(filename,True,False,set(['sage']),None)
    12111017            sage: doctests, extras = FDS.create_doctests(globals())
    12121018            sage: ex = doctests[0].examples[0]
    1213             sage: DTR.tmp_time = walltime() - 1
     1019            sage: ex.walltime = 1.23
    12141020            sage: DTR.report_overtime(sys.stdout.write, doctests[0], ex, 'BAD ANSWER\n')
    12151021            **********************************************************************
    12161022            File ".../sage/doctest/forker.py", line 9, in sage.doctest.forker
    12171023            Failed example:
    12181024                doctest_var = 42; doctest_var^2
    1219             Test ran for ... s
     1025            Test ran for 1.23 s
    12201026        """
    12211027        out(self._failure_header(test, example) +
    1222             "Test ran for %.2f s\n"%(walltime(self.tmp_time)))
     1028            "Test ran for %.2f s\n"%example.walltime)
    12231029
    12241030    def report_unexpected_exception(self, out, test, example, exc_info):
    12251031        """
     
    12291035
    12301036        INPUT:
    12311037
    1232         - ``out`` -- a function for printing (delayed or immediate)
     1038        - ``out`` -- a function for printing
    12331039
    12341040        - ``test`` -- a :class:`doctest.DocTest` instance
    12351041
     
    12511057            sage: _ = sage0.eval("import doctest, sys, os, multiprocessing, subprocess")
    12521058            sage: _ = sage0.eval("from sage.doctest.parsing import SageOutputChecker")
    12531059            sage: _ = sage0.eval("import sage.doctest.forker as sdf")
    1254             sage: _ = sage0.eval("from sage.doctest.control import DocTestDefaults; DD = DocTestDefaults()")
     1060            sage: _ = sage0.eval("from sage.doctest.control import DocTestDefaults")
     1061            sage: _ = sage0.eval("DD = DocTestDefaults(debug=True)")
    12551062            sage: _ = sage0.eval("ex = doctest.Example('E = EllipticCurve([0,0]); E', 'A singular Elliptic Curve')")
    12561063            sage: _ = sage0.eval("DT = doctest.DocTest([ex], globals(), 'singular_curve', None, 0, None)")
    1257             sage: _ = sage0.eval("DTR = sdf.SageDocTestRunner(SageOutputChecker(), output = os.tmpfile(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)")
    1258             sage: _ = sage0.eval("sdf.debug_semaphore = multiprocessing.Semaphore()")
    1259             sage: _ = sage0.eval("sdf.output_semaphore = multiprocessing.Semaphore()")
     1064            sage: _ = sage0.eval("DTR = sdf.SageDocTestRunner(SageOutputChecker(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)")
    12601065            sage: sage0._prompt = r"\(Pdb\) "
    12611066            sage: sage0.eval("DTR.run(DT, clear_globs=False)") # indirect doctest
    12621067            '... "Invariants %s define a singular curve."%ainvs'
     
    12701075            sage: sage0.eval("quit")
    12711076            'TestResults(failed=1, attempted=1)'
    12721077        """
    1273         if debug_semaphore is not None or not self.options.initial or self.no_failure_yet:
     1078        if not self.options.initial or self.no_failure_yet:
    12741079            self.no_failure_yet = False
    12751080            returnval = doctest.DocTestRunner.report_unexpected_exception(self, out, test, example, exc_info)
    1276             if debug_semaphore is not None:
    1277                 debug_semaphore.acquire()
    1278                 output_semaphore.acquire()
     1081            if self.options.debug:
    12791082                self._fakeout.stop_spoofing()
    1280                 self._fakeout.activate_stdin()
     1083                restore_tcpgrp = None
    12811084                try:
     1085                    if os.isatty(0):
     1086                        # In order to read from the terminal, we need
     1087                        # to make the current process group the
     1088                        # foreground group.
     1089                        restore_tcpgrp = os.tcgetpgrp(0)
     1090                        signal.signal(signal.SIGTTIN, signal.SIG_IGN)
     1091                        signal.signal(signal.SIGTTOU, signal.SIG_IGN)
     1092                        os.tcsetpgrp(0, os.getpgrp())
     1093
    12821094                    exc_type, exc_val, exc_tb = exc_info
    12831095                    self.debugger.reset()
    12841096                    self.debugger.interaction(None, exc_tb)
     1097                except KeyboardInterrupt:
     1098                    # Assume this is a *real* interrupt. We need to
     1099                    # escalate this to the master docbuilding process.
     1100                    if not self.options.serial:
     1101                        os.kill(os.getppid(), signal.SIGINT)
     1102                    raise
    12851103                finally:
     1104                    # Restore the foreground process group.
     1105                    if restore_tcpgrp is not None:
     1106                        os.tcsetpgrp(0, restore_tcpgrp)
     1107                        signal.signal(signal.SIGTTIN, signal.SIG_DFL)
     1108                        signal.signal(signal.SIGTTOU, signal.SIG_DFL)
    12861109                    self._fakeout.start_spoofing()
    1287                     self._fakeout.deactivate_stdin()
    1288                     sys.stdout.flush()
    1289                     output_semaphore.release()
    1290                     debug_semaphore.release()
    12911110            return returnval
    12921111
    12931112    def update_results(self, D):
     
    13101129            sage: from sage.doctest.sources import FileDocTestSource, DictAsObject
    13111130            sage: from sage.doctest.control import DocTestDefaults; DD = DocTestDefaults()
    13121131            sage: import doctest, sys, os
    1313             sage: DTR = SageDocTestRunner(SageOutputChecker(), output = os.tmpfile(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
     1132            sage: DTR = SageDocTestRunner(SageOutputChecker(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
    13141133            sage: filename = os.path.join(os.environ['SAGE_ROOT'],'devel','sage','sage','doctest','forker.py')
    13151134            sage: FDS = FileDocTestSource(filename,True,False,set(['sage']),None)
    13161135            sage: doctests, extras = FDS.create_doctests(globals())
     
    13361155        else:
    13371156            return False
    13381157
     1158def dummy_handler(sig, frame):
     1159    """
     1160    Dummy signal handler for SIGCHLD (just to ensure the signal
     1161    isn't ignored).
     1162
     1163    TESTS::
     1164
     1165        sage: import signal
     1166        sage: from sage.doctest.forker import dummy_handler
     1167        sage: _ = signal.signal(signal.SIGUSR1, dummy_handler)
     1168        sage: os.kill(os.getpid(), signal.SIGUSR1)
     1169        sage: signal.signal(signal.SIGUSR1, signal.SIG_DFL)
     1170        <function dummy_handler at ...>
     1171    """
     1172    pass
     1173
    13391174class DocTestDispatcher(SageObject):
    13401175    """
    1341     Creates and dispatches doctesting tasks to workers in series or parallel.
     1176    Creates parallel :class:`DocTestWorker` processes and dispatches
     1177    doctesting tasks.
    13421178    """
    13431179    def __init__(self, controller):
    13441180        """
     
    13541190            <class 'sage.doctest.forker.DocTestDispatcher'>
    13551191        """
    13561192        self.controller = controller
     1193        init_sage()
    13571194
    1358     def _serial_dispatch(self):
     1195    def serial_dispatch(self):
    13591196        """
    13601197        Run the doctests from the controller's specified sources in series.
    13611198
     1199        There is no graceful handling for signals, no possibility of
     1200        interrupting tests and no timeout.
     1201
    13621202        EXAMPLES::
    13631203
    13641204            sage: from sage.doctest.control import DocTestController, DocTestDefaults
     
    13661206            sage: from sage.doctest.reporting import DocTestReporter
    13671207            sage: from sage.doctest.util import Timer
    13681208            sage: import os
    1369             sage: powser = os.path.join(os.environ['SAGE_ROOT'], 'devel', 'sage', 'sage', 'rings', 'homset.py')
    1370             sage: inf = os.path.join(os.environ['SAGE_ROOT'], 'devel', 'sage', 'sage', 'rings', 'ideal.py')
    1371             sage: DC = DocTestController(DocTestDefaults(), [powser, inf])
     1209            sage: homset = os.path.join(os.environ['SAGE_ROOT'], 'devel', 'sage', 'sage', 'rings', 'homset.py')
     1210            sage: ideal = os.path.join(os.environ['SAGE_ROOT'], 'devel', 'sage', 'sage', 'rings', 'ideal.py')
     1211            sage: DC = DocTestController(DocTestDefaults(), [homset, ideal])
    13721212            sage: DC.expand_files_into_sources()
    13731213            sage: DD = DocTestDispatcher(DC)
    13741214            sage: DR = DocTestReporter(DC)
    13751215            sage: DC.reporter = DR
    13761216            sage: DC.dispatcher = DD
    13771217            sage: DC.timer = Timer().start()
    1378             sage: DD._serial_dispatch()
     1218            sage: DD.serial_dispatch()
    13791219            sage -t .../rings/homset.py
    13801220                [... tests, ... s]
    13811221            sage -t .../rings/ideal.py
    13821222                [... tests, ... s]
    13831223        """
    1384         opt = self.controller.options
    1385         sources = self.controller.sources
    1386         try:
    1387             for source in sources:
    1388                 output = os.tmpfile()
    1389                 result = DocTestTask(source)(None, output, opt)
    1390                 output.seek(0)
    1391                 output = output.read()
    1392                 self.controller.reporter.report(source, False, 0, result, output)
    1393         except KeyboardInterrupt:
    1394             print "Tesing %s interrupted!"%(source.basename)
    1395             sys.stdout.flush()
    1396             # We rely on the reporter to give more information back to the user.
     1224        for source in self.controller.sources:
     1225            head = self.controller.reporter.report_head(source)
     1226            self.controller.log(head)
     1227            outtmpfile = os.tmpfile()
     1228            result = DocTestTask(source)(self.controller.options, outtmpfile)
     1229            outtmpfile.seek(0)
     1230            output = outtmpfile.read()
     1231            self.controller.reporter.report(source, False, 0, result, output)
    13971232
    1398     def _parallel_dispatch(self):
     1233    def parallel_dispatch(self):
    13991234        """
    1400         Run the doctests from the controller's specified sources in series.
     1235        Run the doctests from the controller's specified sources in parallel.
     1236
     1237        This creates :class:DocTestWorker subprocesses, while the master
     1238        process checks for timeouts and collects and displays the results.
    14011239
    14021240        EXAMPLES::
    14031241
     
    14151253            sage: DC.reporter = DR
    14161254            sage: DC.dispatcher = DD
    14171255            sage: DC.timer = Timer().start()
    1418             sage: DD._parallel_dispatch()
     1256            sage: DD.parallel_dispatch()
    14191257            sage -t .../databases/cremona.py
    14201258                [... tests, ... s]
    14211259            sage -t .../rings/big_oh.py
    14221260                [... tests, ... s]
    14231261        """
    14241262        opt = self.controller.options
    1425         sources = self.controller.sources
    1426         nthreads = opt.nthreads
    1427         tasks = multiprocessing.JoinableQueue(len(sources)+nthreads)
    1428         for source in sources:
    1429             tasks.put(DocTestTask(source))
    1430         results = multiprocessing.Queue(len(sources))
    1431         workers = [DocTestWorker(tasks, results, options=opt) for i in xrange(nthreads)]
    1432         for w in workers:
    1433             w.start()
    1434             tasks.put(None)
    1435         done_count = 0
    1436         while True:
    1437             try:
    1438                 result = results.get()
    1439                 if result is None:
    1440                     done_count += 1
    1441                     if done_count >= len(workers):
     1263        source_iter = iter(self.controller.sources)
     1264
     1265        # If timeout was 0, simply set a very long time
     1266        if opt.timeout <= 0:
     1267            opt.timeout = 2**60
     1268        # Timeout we give a process to die (after it received a SIGHUP
     1269        # signal). If it doesn't exit by itself in this many seconds, we
     1270        # SIGKILL it. This is 5% of doctest timeout, with a maximum of
     1271        # 10 minutes.
     1272        die_timeout = opt.timeout * 0.05
     1273        if die_timeout > 600:
     1274            die_timeout = 600
     1275
     1276        # List of alive DocTestWorkers (child processes). Workers which
     1277        # are done but whose messages have not been read are also
     1278        # considered alive.
     1279        workers = []
     1280       
     1281        # List of DocTestWorkers which have finished running but
     1282        # whose results have not been reported yet.
     1283        finished = []
     1284       
     1285        # One particular worker that we are "following": we report the
     1286        # messages while it's running. For other workers, we report the
     1287        # messages if there is no followed worker.
     1288        follow = None
     1289
     1290        # Install signal handler for SIGCHLD
     1291        signal.signal(signal.SIGCHLD, dummy_handler)
     1292
     1293        # Logger
     1294        log = self.controller.log
     1295
     1296        from sage.ext.pselect import PSelecter
     1297        try:
     1298            # Block SIGCHLD and SIGINT except during the pselect() call
     1299            with PSelecter([signal.SIGCHLD, signal.SIGINT]) as sel:
     1300                # Function to execute in the child process which exits
     1301                # this "with" statement (which restores the signal mask)
     1302                # and resets to SIGCHLD handler to default.
     1303                # Since multiprocessing.Process is implemented using
     1304                # fork(), signals would otherwise remain blocked in the
     1305                # child process.
     1306                def sel_exit():
     1307                    signal.signal(signal.SIGCHLD, signal.SIG_DFL)
     1308                    sel.__exit__(None, None, None)
     1309
     1310                while True:
     1311                    # To avoid calling time.time() all the time while
     1312                    # checking for timeouts, we call it here, once per
     1313                    # loop. It's not a problem if this isn't very
     1314                    # precise, doctest timeouts don't need millisecond
     1315                    # precision.
     1316                    now = time.time()
     1317
     1318                    # If there were any substantial changes in the state
     1319                    # (new worker started or finished worker reported),
     1320                    # restart this while loop instead of calling pselect().
     1321                    # This ensures internal consistency and a reasonably
     1322                    # accurate value for "now".
     1323                    restart = False
     1324   
     1325                    # Process all workers. Check for timeouts on active
     1326                    # workers and move finished/crashed workers to the
     1327                    # "finished" list.
     1328                    # Create a new list "new_workers" containing the active
     1329                    # workers (to avoid updating "workers" in place).
     1330                    new_workers = []
     1331                    for w in workers:
     1332                        if w.rmessages is not None or w.is_alive():
     1333                            if now >= w.deadline:
     1334                                # Timeout => (try to) kill the process
     1335                                # group (which normally includes
     1336                                # grandchildren) and close the message
     1337                                # pipe.
     1338                                # We don't report the timeout yet, we wait
     1339                                # until the process has actually died.
     1340                                w.kill()
     1341                                w.deadline = now + die_timeout
     1342                            if not w.is_alive():
     1343                                # Worker is done but we haven't read all
     1344                                # messages (possibly a grandchild still
     1345                                # has the messages pipe open).
     1346                                # Adjust deadline to read all messages:
     1347                                newdeadline = now + die_timeout
     1348                                if w.deadline > newdeadline:
     1349                                    w.deadline = newdeadline
     1350                            new_workers.append(w)
     1351                        else:
     1352                            # Save the result and output of the worker
     1353                            # and close the associated file descriptors.
     1354                            # It is important to do this now. If we
     1355                            # would leave them open until we call
     1356                            # report(), parallel testing can easily fail
     1357                            # with a "Too many open files" error.
     1358                            w.save_result_output()
     1359                            finished.append(w)
     1360                    workers = new_workers
     1361
     1362                    # Similarly, process finished workers.
     1363                    new_finished = []
     1364                    for w in finished:
     1365                        if follow is not None and follow is not w:
     1366                            # We are following a different worker, so
     1367                            # we cannot report now
     1368                            new_finished.append(w)
     1369                        else:
     1370                            # Report the completion of this worker
     1371                            if w.heading is not None:
     1372                                log(w.heading)
     1373                            log(w.messages, end="")
     1374                            self.controller.reporter.report(
     1375                                w.source,
     1376                                w.killed,
     1377                                w.exitcode,
     1378                                w.result,
     1379                                w.output)
     1380                            restart = True
     1381                            follow = None
     1382                    finished = new_finished
     1383   
     1384                    # Start new workers if possible
     1385                    while source_iter is not None and len(workers) < opt.nthreads:
     1386                        try:
     1387                            source = source_iter.next()
     1388                        except StopIteration:
     1389                            source_iter = None
     1390                        else:
     1391                            # Start a new worker.
     1392                            w = DocTestWorker(source, options=opt, funclist=[sel_exit])
     1393                            w.heading = self.controller.reporter.report_head(w.source)
     1394                            if opt.nthreads == 1:
     1395                                # With 1 process, the child prints
     1396                                # directly to stdout, so we need to
     1397                                # log the heading now.
     1398                                log(w.heading)
     1399                                w.heading = None
     1400                            w.start()  # This might take some time
     1401                            w.deadline = time.time() + opt.timeout
     1402                            workers.append(w)
     1403                            restart = True
     1404
     1405                    # Recompute state if needed
     1406                    if restart:
     1407                        continue
     1408   
     1409                    # We are finished if there are no DocTestWorkers left
     1410                    if len(workers) == 0:
     1411                        # If there are no active workers, we should have
     1412                        # reported all finished workers.
     1413                        assert len(finished) == 0
    14421414                        break
    1443                 else:
     1415       
     1416                    # The master pselect() call
     1417                    rlist = [w.rmessages for w in workers if w.rmessages is not None]
     1418                    tmout = min(w.deadline for w in workers) - now
     1419                    if tmout > 5:  # Wait at most 5 seconds
     1420                        tmout = 5
     1421                    rlist, _, _, _ = sel.pselect(rlist, timeout=tmout)
     1422   
     1423                    # Read messages
     1424                    for w in workers:
     1425                        if w.rmessages is not None and w.rmessages in rlist:
     1426                            w.read_messages()
     1427
     1428                    # Find a worker to follow: if there is only one worker,
     1429                    # always follow it. Otherwise, take the worker with
     1430                    # the earliest deadline of all workers with messages.
     1431                    if follow is None:
     1432                        if len(workers) == 1:
     1433                            follow = workers[0]
     1434                        else:
     1435                            for w in workers:
     1436                                if w.messages:
     1437                                    if follow is None or w.deadline < follow.deadline:
     1438                                        follow = w
     1439
     1440                    # Write messages of followed worker
     1441                    if follow is not None:
     1442                        if follow.heading is not None:
     1443                            log(follow.heading)
     1444                            follow.heading = None
     1445                        log(follow.messages, end="")
     1446                        follow.messages = ""
     1447        finally:
     1448            for w in workers:
     1449                try:
     1450                    print("Killing test", w.source.printpath)
     1451                    w.kill()
     1452                except Exception:
     1453                    pass
     1454            # Fork a child process with the specific purpose of
     1455            # killing the remaining workers.
     1456            if len(workers) > 0 and os.fork() == 0:
     1457                # Block these signals
     1458                with PSelecter([signal.SIGHUP, signal.SIGINT]):
    14441459                    try:
    1445                         if output_semaphore is not None:
    1446                             output_semaphore.acquire()
    1447                         self.controller.reporter.report(*result)
     1460                        from time import sleep
     1461                        sleep(die_timeout)
     1462                        for w in workers:
     1463                            try:
     1464                                w.kill()
     1465                            except Exception:
     1466                                pass
    14481467                    finally:
    1449                         sys.stdout.flush()
    1450                         if output_semaphore is not None:
    1451                             output_semaphore.release()
    1452             except Empty:
    1453                 time.sleep(.05)
     1468                        os._exit(0)
     1469           
     1470            # Hack to ensure multiprocessing leaves these processes alone
     1471            multiprocessing.current_process()._children = set()
    14541472
    14551473    def dispatch(self): # todo, nthreads=options.nthreads, streaming=False, verbose=options.verbose, debug=options.debug, run_id=run_id
    14561474        """
    1457         Runs the doctests for the controller's specified sources.
    1458 
    1459         It will run in series or parallel depending on the ``serial``
    1460         option on the controller's option object.
     1475        Run the doctests for the controller's specified sources,
     1476        by calling :meth:`parallel_dispatch` or :meth:`serial_dispatch`
     1477        according to the ``--serial`` option.
    14611478
    14621479        EXAMPLES::
    14631480
     
    14811498            sage -t .../sage/rings/big_oh.py
    14821499                [... tests, ... s]
    14831500        """
    1484         init_sage()
    1485         global debug_semaphore, output_semaphore
    1486         try:
    1487             output_semaphore = multiprocessing.Semaphore()
    1488             if self.controller.options.debug:
    1489                 debug_semaphore = multiprocessing.Semaphore()
    1490             if self.controller.options.serial:
    1491                 self._serial_dispatch()
    1492             else:
    1493                 self._parallel_dispatch()
    1494         finally:
    1495             output_semaphore = None
    1496             debug_semaphore = None
     1501        if self.controller.options.serial:
     1502            self.serial_dispatch()
     1503        else:
     1504            self.parallel_dispatch()
     1505
    14971506
    14981507class DocTestWorker(multiprocessing.Process):
    14991508    """
    1500     The DocTestWorker process pulls tasks from its task queue and runs
    1501     them, putting the results onto its result queue.
     1509    The DocTestWorker process runs one :class:`DocTestTask` for a given
     1510    source. It returns messages about doctest failures (or all tests if
     1511    verbose doctesting) though a pipe and returns results through a
     1512    ``multiprocessing.Queue`` instance (both these are created in the
     1513    :meth:`start` method).
    15021514
    1503     It can recover gracefully from timeouts and segfaults in the
    1504     tasks.
     1515    It runs the task in its own process-group, such that killing the
     1516    process group kills this process together with its child processes.
     1517
     1518    The class has additional methods and attributes for bookkeeping
     1519    by the master process. Except in :meth:`run`, nothing from this
     1520    class should be accessed by the child process.
    15051521
    15061522    INPUT:
    15071523
    1508     - ``task_queue`` -- a :class:multiprocessing.Queue instance
     1524    - ``source`` -- a :class:DocTestSource instance
    15091525
    1510     - ``result_queue`` -- a :class:multiprocessing.Queue instance
     1526    - ``options`` -- an object representing doctest options.
    15111527
    1512     - ``timeout`` -- a positive number
    1513 
    1514     - ``verbose`` -- a boolean, controls verbosity when killing processes.
     1528    - ``funclist`` -- a list of callables to be called at the start of
     1529      the child process.
    15151530
    15161531    EXAMPLES::
    15171532
    1518         sage: import multiprocessing, os, time
    15191533        sage: from sage.doctest.forker import DocTestWorker, DocTestTask
    15201534        sage: from sage.doctest.sources import FileDocTestSource
    15211535        sage: from sage.doctest.reporting import DocTestReporter
    15221536        sage: from sage.doctest.control import DocTestController, DocTestDefaults
    1523         sage: tasks = multiprocessing.JoinableQueue(2)
    1524         sage: filename = os.path.join(os.environ['SAGE_ROOT'],'devel','sage','sage','doctest','sources.py')
     1537        sage: filename = os.path.join(os.environ['SAGE_ROOT'],'devel','sage','sage','doctest','util.py')
    15251538        sage: DD = DocTestDefaults()
     1539        sage: FDS = FileDocTestSource(filename,True,False,set(['sage']),None)
     1540        sage: W = DocTestWorker(FDS, DD)
     1541        sage: W.start()
    15261542        sage: DC = DocTestController(DD, filename)
    1527         sage: FDS = FileDocTestSource(filename,True,False,set(['sage']),None)
    1528         sage: DTT = DocTestTask(FDS)
    1529         sage: tasks.put(DTT)
    1530         sage: tasks.put(None)
    1531         sage: results = multiprocessing.Queue(1)
    1532         sage: W = DocTestWorker(tasks, results, DD)
    1533         sage: from Queue import Empty
    1534         sage: W.start()
    15351543        sage: reporter = DocTestReporter(DC)
    1536         sage: while True:
    1537         ....:     try:
    1538         ....:         result = results.get()
    1539         ....:         if result is None: break
    1540         ....:         reporter.report(*result)
    1541         ....:     except Empty:
    1542         ....:         time.sleep(0.05)
    1543         ....:
    1544         sage -t .../sage/doctest/sources.py
     1544        sage: W.join()  # Wait for worker to finish
     1545        sage: result = W.result_queue.get()
     1546        sage: reporter.report(FDS, False, W.exitcode, result, "")
    15451547            [... tests, ... s]
    15461548    """
    1547     def __init__(self, task_queue, result_queue, options):
     1549    def __init__(self, source, options, funclist=[]):
    15481550        """
    15491551        Initialization.
    15501552
     
    15641566                cumulative wall time: ... seconds
    15651567        """
    15661568        multiprocessing.Process.__init__(self)
    1567         self.task_queue = task_queue
    1568         self.result_queue = result_queue
     1569
     1570        self.source = source
    15691571        self.options = options
     1572        self.funclist = funclist
     1573
     1574        # Open pipe for messages. These are raw file descriptors,
     1575        # not Python file objects!
     1576        self.rmessages, self.wmessages = os.pipe()
     1577
     1578        # Create Queue for the result. Since we're running only one
     1579        # doctest, this "queue" will contain only 1 element.
     1580        self.result_queue = multiprocessing.Queue(1)
     1581
     1582        # Temporary file for stdout/stderr of the child process.
     1583        # Normally, this isn't used in the master process except to
     1584        # debug timeouts/crashes.
     1585        self.outtmpfile = os.tmpfile()
     1586
     1587        # Create string for the master process to store the messages
     1588        # (usually these are the doctest failures) of the child.
     1589        # These messages are read through the pipe created above.
     1590        self.messages = ""
     1591
     1592        # Has this worker been killed (because of a time out)?
     1593        self.killed = False
    15701594
    15711595    def run(self):
    15721596        """
    1573         Iterates through the tasks in the task queue and runs the
    1574         doctests in the corresponding sources.
     1597        Runs the :class:`DocTestTask` under its own PGID.
    15751598
    15761599        TESTS::
    15771600
     
    15881611                cpu time: ... seconds
    15891612                cumulative wall time: ... seconds
    15901613        """
    1591         while True:
    1592             next_task = self.task_queue.get()
    1593             if next_task is None:
    1594                 self.task_queue.task_done()
    1595                 self.result_queue.put(None)
    1596                 break
    1597             result_pipe = multiprocessing.Queue() # pipes block
    1598             output_file = os.tmpfile()
    1599             p = multiprocessing.Process(target = next_task, args=(result_pipe,output_file,self.options))
    1600             try:
    1601                 p.start()
    1602                 ## We would like to do the following:
    1603                 # results = result_pipe.get(timeout=self.options.timeout)
    1604                 # p.join(timeout=self.options.timeout)
    1605                 ## But this hangs when the underlying process segfaults.
    1606                 ## So instead we query the underlying process manually.
    1607                 maxwait = 0.1
    1608                 curwait = 0.004
    1609                 deathwait = 1
    1610                 results = None
    1611                 t = walltime()
    1612                 alive = True
    1613                 while True:
    1614                     try:
    1615                         results = result_pipe.get(timeout=curwait)
    1616                     except Empty:
    1617                         curwait *= 2
    1618                         if curwait > maxwait:
    1619                             curwait = maxwait
    1620                     if results is not None or walltime(t) >= self.options.timeout:
    1621                         break
    1622                     if not p.is_alive():
    1623                         if not alive:
    1624                             # We've already waited, but results is still None
    1625                             results = 0, DictAsObject(dict(err='noresult')), ""
    1626                             break
    1627                         alive = False
    1628                         if results is None:
    1629                             curwait = deathwait
    1630                 answer = next_task.source, walltime(t) >= self.options.timeout, p.exitcode, results
    1631             ## This except block was used in the approch mentioned above
    1632             #except Empty:
    1633             #    answer = next_task.source, True, -1, None
    1634             except KeyboardInterrupt:
    1635                 if output_semaphore is not None:
    1636                     output_semaphore.acquire()
    1637                 try:
    1638                     print "Testing %s interrupted!"%(next_task.source.basename)
    1639                 finally:
    1640                     sys.stdout.flush()
    1641                     if output_semaphore is not None:
    1642                         output_semaphore.release()
    1643                 # We quietly die: the child process is killed in the finally block.
    1644                 break
    1645             finally:
    1646                 output_file.seek(0)
    1647                 output = output_file.read()
    1648                 self.annihilate(p, False)
    1649             self.task_queue.task_done()
    1650             answer = answer + (output,)
    1651             self.result_queue.put(answer)
     1614        os.setpgid(os.getpid(), os.getpid())
    16521615
    1653     def annihilate(self, p, verbose):
     1616        # Run functions
     1617        for f in self.funclist:
     1618            f()
     1619
     1620        task = DocTestTask(self.source)
     1621
     1622        # Ensure the Python stdin is the actual stdin
     1623        # (multiprocessing redirects this).
     1624        # We will do a more proper redirect of stdin in SageSpoofInOut.
     1625        sys.stdin = os.fdopen(0, "r")
     1626
     1627        # Close the reading end of the pipe (only the master should
     1628        # read from the pipe) and open the writing end.
     1629        os.close(self.rmessages)
     1630        msgpipe = os.fdopen(self.wmessages, "w")
     1631        try:
     1632            # If we have only one process, we print directly to stdout
     1633            # without using the message pipe. This is mainly needed to
     1634            # support the --debug option.
     1635            if self.options.nthreads == 1:
     1636                msgpipe.close()
     1637                msgpipe = None
     1638
     1639            task(self.options, self.outtmpfile, msgpipe, self.result_queue)
     1640        finally:
     1641            if msgpipe is not None:
     1642                msgpipe.close()
     1643
     1644    def start(self):
    16541645        """
    1655         Kills the process p and all of its descendents.
     1646        Start the worker and close the writing end of the message pipe.
     1647        """
     1648        super(DocTestWorker, self).start()
    16561649
    1657         INPUT:
     1650        # Close the writing end of the pipe (only the child should
     1651        # write to the pipe).
     1652        os.close(self.wmessages)
    16581653
    1659         - ``p`` -- a process to kill
     1654    def read_messages(self):
     1655        """
     1656        In the master process, read from the pipe and store the data
     1657        read in the ``messages`` attribute.
     1658        """
     1659        # It's absolutely important to execute only one read() system
     1660        # call, more might block. Assuming that we used pselect()
     1661        # correctly, one read() will not block.
     1662        if self.rmessages is not None:
     1663            s = os.read(self.rmessages, 4096)
     1664            self.messages += s
     1665            if len(s) == 0:  # EOF
     1666                os.close(self.rmessages)
     1667                self.rmessages = None
    16601668
    1661         - ``verbose`` -- boolean
     1669    def save_result_output(self):
     1670        """
     1671        Annotate ``self`` with ``self.result`` (the result read through
     1672        the ``result_queue`` and with ``self.output``, the complete
     1673        contents of ``self.outtmpfile``. Then close the Queue and
     1674        ``self.outtmpfile``.
     1675        """
     1676        from Queue import Empty
     1677        try:
     1678            self.result = self.result_queue.get(block=False)
     1679        except Empty:
     1680            self.result = (0, DictAsObject(dict(err='noresult')))
     1681        del self.result_queue
    16621682
    1663         EXAMPLES::
     1683        self.outtmpfile.seek(0)
     1684        self.output = self.outtmpfile.read()
     1685        del self.outtmpfile
    16641686
    1665             sage: from sage.doctest.forker import DocTestWorker
    1666             sage: DTW = DocTestWorker(None, None, None)
    1667             sage: from multiprocessing import Process
    1668             sage: import time
    1669             sage: def make_babies():
    1670             ....:     for i in range(3):
    1671             ....:         p = Process(target = time.sleep, args = (4,))
    1672             ....:         p.start()
    1673             ....:     time.sleep(6)
    1674             ....:
    1675             sage: p = Process(target = make_babies)
    1676             sage: p.start()
    1677             sage: p.is_alive()
    1678             True
    1679             sage: DTW.annihilate(p, True)
    1680             killing ...
    1681             subprocesses [...]
    1682             sage: p.is_alive()
    1683             False
     1687    def kill(self):
    16841688        """
    1685         ## The proper way to do this is to create a process group.
    1686         ## But then control-Z doesn't get forwarded automatically....
    1687         #        os.system("ps -fTj")
    1688         #        os.system("./pstree -p %s" % os.getpid())
    1689         #        os.system("kill -9 -%s" % p.pid)
    1690         #        os.system("kill -9 %s" % p.pid)
    1691         #        os.killpg(p.pid, signal.SIGSTOP)
    1692         def kill_all(pids, sig):
    1693             for pid in pids:
    1694                 try:
    1695                     os.kill(pid, sig)
    1696                 except OSError:
    1697                     pass
    1698         def all_subprocesses(root_pid):
    1699             listing = subprocess.Popen(['ps', '-o', 'pid,ppid'], stdout=subprocess.PIPE).communicate()[0].split('\n')[1:]
    1700             children = defaultdict(list)
    1701             for line in listing:
    1702                 line = line.strip()
    1703                 if line:
    1704                     pid, ppid = [int(s.strip()) for s in line.split(' ') if s]
    1705                     children[ppid].append(pid)
    1706             all = []
    1707             def add_children(ppid):
    1708                 for pid in children[ppid]:
    1709                     all.append(pid)
    1710                     add_children(pid)
    1711             add_children(root_pid)
    1712             return all
    1713         if p.is_alive() and verbose:
    1714             print "killing", p.pid
    1715         if p.is_alive():
    1716             subprocesses = all_subprocesses(p.pid)
    1717             if verbose:
    1718                 print "subprocesses", subprocesses
    1719             p.terminate()
    1720             p.join(1)
    1721             if subprocesses:
    1722                 kill_all(reversed(subprocesses), signal.SIGTERM)
    1723                 time.sleep(.1)
    1724                 kill_all(reversed(subprocesses), signal.SIGKILL)
    1725                 p.join(1)
    1726         if p.is_alive():
    1727             os.kill(p.pid, signal.SIGKILL)
    1728             p.join(1)
     1689        Kill this worker. The first time this is called, use
     1690        ``SIGHUP``. Subsequent times, use ``SIGKILL``.  Also close the
     1691        message pipe if it was still open.
     1692        """
     1693        if self.rmessages is not None:
     1694            os.close(self.rmessages)
     1695            self.rmessages = None
     1696        if not self.killed:
     1697            self.killed = True
     1698            os.killpg(self.pid, signal.SIGHUP)
     1699        else:
     1700            os.killpg(self.pid, signal.SIGKILL)
     1701
    17291702
    17301703class DocTestTask(object):
    17311704    """
    1732     This class encapsulates the tests from a single source.  It can be
    1733     called in series (via :meth:`DocTestDispatcher._serial_dispatch`)
    1734     or in parallel through :class:`DocTestWorker` instances.
     1705    This class encapsulates the tests from a single source.
    17351706
    17361707    This class does not insulate from problems in the source
    1737     (e.g. entering an infinite loop or causing a segfault).
     1708    (e.g. entering an infinite loop or causing a segfault), that has to
     1709    be dealt with at a higher level.
    17381710
    17391711    INPUT:
    17401712
     
    17531725        sage: DTT = DocTestTask(FDS)
    17541726        sage: DD = DocTestDefaults()
    17551727        sage: DC = DocTestController(DD,[filename])
    1756         sage: ntests, results, delayed_output = DTT(output = os.tmpfile(),options=DD); ntests
    1757         276
     1728        sage: ntests, results = DTT(options=DD)
     1729        sage: ntests
     1730        273
    17581731        sage: sorted(results.keys())
    17591732        ['cputime', 'err', 'failures', 'walltime']
    17601733    """
     
    17741747        """
    17751748        self.source = source
    17761749
    1777     def __call__(self, result_pipe=None, output=None, options=None):
     1750    def __call__(self, options, outtmpfile=None, msgfile=None, result_queue=None):
    17781751        """
    17791752        Calling the task does the actual work of running the doctests.
    17801753
    17811754        INPUT:
    17821755
    1783         - ``result_pipe`` -- either None (if run in series) or a :class:`multiprocessing.Queue`
     1756        - ``options`` -- an object representing doctest options.
    17841757
    1785         - ``output`` -- a temporary file that's used by the doctest runner to redirect stdout.
     1758        - ``outtmpfile`` -- a seekable file that's used by the doctest
     1759          runner to redirect stdout and stderr.
     1760
     1761        - ``msgfile`` -- a file or pipe to send doctest messages about
     1762          doctest failures (or all tests in verbose mode).
     1763
     1764        - ``result_queue`` -- an instance of :class:`multiprocessing.Queue`
     1765          to store the doctest result. For testing, this can also be None.
    17861766
    17871767        OUPUT:
    17881768
    1789         - If ``result_pipe`` is None, returns a pair ``(doctests,
    1790           runner)``, where ``doctests`` is a list of
    1791           :class:`doctest.DocTest` instances and ``runner`` is an
    1792           annotated ``SageDocTestRunner`` instance.
     1769        - ``(doctests, runner)`` where ``doctests`` is the number of
     1770          doctests and and ``runner`` is an annotated
     1771          ``SageDocTestRunner`` instance.
    17931772
    1794         - If ``result_pipe`` is not None, puts ``(doctests, runner)``
    1795           onto the result pipe and returns nothing.
     1773        - Also put ``(doctests, runner)`` onto the ``result_queue``
     1774          if the latter isn't None.
    17961775
    17971776        EXAMPLES::
    17981777
     
    18051784            sage: DTT = DocTestTask(FDS)
    18061785            sage: DD = DocTestDefaults()
    18071786            sage: DC = DocTestController(DD, [filename])
    1808             sage: ntests, runner, delayed_output = DTT(None, os.tmpfile(), DD)
     1787            sage: ntests, runner = DTT(options=DD)
    18091788            sage: runner.failures
    18101789            0
    18111790            sage: ntests
    1812             192
     1791            202
    18131792        """
    18141793        result = None
    18151794        try:
    18161795            file = self.source.path
    18171796            basename = self.source.basename
    18181797            import sage.all_cmdline
    1819             runner = SageDocTestRunner(SageOutputChecker(), verbose=options.verbose, output=output, sage_options=options, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
     1798            runner = SageDocTestRunner(
     1799                    SageOutputChecker(),
     1800                    verbose=options.verbose,
     1801                    outtmpfile=outtmpfile,
     1802                    msgfile=msgfile,
     1803                    sage_options=options,
     1804                    optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
    18201805            runner.basename = basename
    18211806            N = options.file_iterations
    18221807            results = DictAsObject(dict(walltime=[],cputime=[],err=None))
    1823             if options.verbose:
    1824                 # This will cause summaries to print immediately
    1825                 delayed_summaries = None
    1826             else:
    1827                 delayed_summaries = []
    18281808            for it in range(N):
    18291809                sage_namespace = RecordingDict(dict(sage.all_cmdline.__dict__))
    18301810                sage_namespace['__name__'] = '__main__'
     
    18351815                for test in doctests:
    18361816                    runner.run(test)
    18371817                runner.filename = file
    1838                 if output_semaphore is not None:
    1839                     output_semaphore.acquire()
    1840                 failed, tried = runner.summarize(verbose=options.verbose, delay_list=delayed_summaries)
    1841                 if output_semaphore is not None:
    1842                     sys.stdout.flush()
    1843                     output_semaphore.release()
     1818                failed, tried = runner.summarize(options.verbose)
    18441819                timer.stop().annotate(runner)
    18451820                if runner.update_results(results):
    18461821                    break
     
    18481823                results.err = 'tab'
    18491824                results.tab_linenos = extras['tab']
    18501825            # We subtract 1 to remove the sig_on_count() tests
    1851             if delayed_summaries is None:
    1852                 delayed_summaries = ""
    1853             else:
    1854                 delayed_summaries = "".join(delayed_summaries)
    1855             result = sum([max(0,len(test.examples) - 1) for test in doctests]), results, delayed_summaries
    1856         except KeyboardInterrupt:
    1857             if result_pipe is None:
    1858                 # We're in serial mode
    1859                 raise
    1860             # Otherwise, we've been started by a worker: we'll return the result in the finally block
    1861             result = 0, DictAsObject(dict(err='ctlC')), ""
    1862         except IOError:
    1863             # File doesn't exist
    1864             result = 0, DictAsObject(dict(err='file')), ""
    1865         except Exception:
     1826            result = (sum([max(0,len(test.examples) - 1) for test in doctests]), results)
     1827        except BaseException:
    18661828            exc_info = sys.exc_info()
    18671829            tb = "".join(traceback.format_exception(*exc_info))
    1868             result = 0, DictAsObject(dict(err=exc_info[0], tb=tb)), ""
    1869         finally:
    1870             if result_pipe is None:
    1871                 return result
    1872             else:
    1873                 result_pipe.put(result, False)
     1830            result = (0, DictAsObject(dict(err=exc_info[0], tb=tb)))
     1831
     1832        if result_queue is not None:
     1833            result_queue.put(result, False)
     1834        return result
  • sage/doctest/parsing.py

    diff --git a/sage/doctest/parsing.py b/sage/doctest/parsing.py
    a b  
    1212#                          William Stein <wstein@gmail.com>
    1313#
    1414#  Distributed under the terms of the GNU General Public License (GPL)
    15 #
     15#  as published by the Free Software Foundation; either version 2 of
     16#  the License, or (at your option) any later version.
    1617#                  http://www.gnu.org/licenses/
    1718#*****************************************************************************
    1819
     20
    1921import re, sys
    2022import doctest
    2123from sage.misc.preparser import preparse
    2224from Cython.Build.Dependencies import strip_string_literals
    2325
    2426float_regex = re.compile('([+-]?((\d*\.?\d+)|(\d+\.?))([eE][+-]?\d+)?)')
    25 optional_regex = re.compile(r'(long time|not implemented|not tested|known bug)|(optional\s*[:-]?\s*(\w*))')
     27optional_regex = re.compile(r'(long time|not implemented|not tested|known bug)|([^ a-z]\s*optional\s*[:-]*((\s|\w)*))')
    2628find_sage_prompt = re.compile(r"^(\s*)sage: ", re.M)
    2729find_sage_continuation = re.compile(r"^(\s*)\.\.\.\.:", re.M)
    2830random_marker = re.compile('.*random', re.I)
     
    4446    EXAMPLES::
    4547
    4648        sage: from sage.doctest.parsing import parse_optional_tags
    47         sage: parse_optional_tags("    sage: magma('2 + 2') # optional: magma")
     49        sage: parse_optional_tags("sage: magma('2 + 2')# optional: magma")
    4850        set(['magma'])
    49         sage: sorted(list(parse_optional_tags("    sage: factor(10^(10^10) + 1) # long time, not tested")))
    50         ['long time', 'not tested']
     51        sage: parse_optional_tags("sage: #optional -- mypkg")
     52        set(['mypkg'])
     53        sage: parse_optional_tags("sage: print(1)  # parentheses are optional here")
     54        set([])
     55        sage: parse_optional_tags("sage: print(1)  # optional")
     56        set([''])
     57        sage: sorted(list(parse_optional_tags("sage: #optional -- foo bar, baz")))
     58        ['bar', 'foo']
     59        sage: sorted(list(parse_optional_tags("    sage: factor(10^(10^10) + 1) # LoNg TiME, NoT TeSTED; OptioNAL -- P4cka9e")))
     60        ['long time', 'not tested', 'p4cka9e']
    5161        sage: parse_optional_tags("    sage: raise RuntimeError # known bug")
    5262        set(['known bug'])
    5363        sage: sorted(list(parse_optional_tags("    sage: determine_meaning_of_life() # long time, not implemented")))
    5464        ['long time', 'not implemented']
     65
     66    We don't parse inside strings::
     67
     68        sage: parse_optional_tags("    sage: print '  # long time'")
     69        set([])
     70        sage: parse_optional_tags("    sage: print '  # long time'  # not tested")
     71        set(['not tested'])
    5572    """
    5673    safe, literals = strip_string_literals(string)
    5774    first_line = safe.split('\n', 1)[0]
     
    5976        return set()
    6077    comment = first_line[first_line.find('#')+1:]
    6178    # strip_string_literals replaces comments
    62     comment = literals[comment]
    63     return set(m.group(1) or m.group(3) for m in optional_regex.finditer(comment.lower()))
     79    comment = "#" + (literals[comment]).lower()
     80
     81    tags = []
     82    for m in optional_regex.finditer(comment):
     83        if m.group(1):
     84            tags.append(m.group(1))
     85        else:
     86            tags.extend(m.group(3).split() or [""])
     87    return set(tags)
    6488
    6589def parse_tolerance(source, want):
    6690    """
     
    616640            False
    617641            sage: OC.check_output(zerorel,ten,optflag)
    618642            False
     643
     644        TESTS:
     645
     646        More explicit tolerance checks::
     647
     648            sage: _ = x  # rel tol 1e10
     649            sage: raise RuntimeError   # rel tol 1e10
     650            Traceback (most recent call last):
     651            ...
     652            RuntimeError
     653            sage: 1  # abs tol 2
     654            -0.5
     655            sage: print "1.000009"   # abs tol 1e-5
     656            1.0
    619657        """
    620658        if isinstance(want, MarkedOutput):
    621659            if want.random:
  • sage/doctest/reporting.py

    diff --git a/sage/doctest/reporting.py b/sage/doctest/reporting.py
    a b  
    11"""
    22This module determines how doctest results are reported to the user.
    33
     4It also computes the exit status in the ``error_status`` attribute of
     5:class:DocTestReporter. This is a bitwise OR of the following bits:
     6
     7- 1: Doctest failure
     8- 2: Bad command line syntax or invalid options
     9- 4: Test timed out
     10- 8: Test exited with non-zero status
     11- 16: Test crashed with a signal (e.g. segmentation fault)
     12- 32: TAB character found
     13- 64: Internal error in the doctesting framework
     14- 128: Testing interrupted, not all tests run
     15
     16
    417AUTHORS:
    518
    619- David Roe (2012-03-27) -- initial version, based on Robert Bradshaw's code.
     
    1023#       Copyright (C) 2012 David Roe <roed.math@gmail.com>
    1124#                          Robert Bradshaw <robertwb@gmail.com>
    1225#                          William Stein <wstein@gmail.com>
     26#       Copyright (C) 2013 Jeroen Demeyer <jdemeyer@cage.ugent.be>
    1327#
    1428#  Distributed under the terms of the GNU General Public License (GPL)
    15 #
     29#  as published by the Free Software Foundation; either version 2 of
     30#  the License, or (at your option) any later version.
    1631#                  http://www.gnu.org/licenses/
    1732#*****************************************************************************
    1833
    19 import sys
     34
     35import sys, signal
    2036from sage.structure.sage_object import SageObject
    2137from sage.doctest.util import count_noun
     38from sage.doctest.sources import DictAsObject
     39
     40def signal_name(sig):
     41    """
     42    Return a string describing a signal number.
     43
     44    EXAMPLES::
     45
     46        sage: import signal
     47        sage: from sage.doctest.reporting import signal_name
     48        sage: signal_name(signal.SIGSEGV)
     49        'segmentation fault'
     50        sage: signal_name(9)
     51        'kill signal'
     52        sage: signal_name(12345)
     53        'signal 12345'
     54    """
     55    if sig == signal.SIGHUP:
     56        return "hangup"
     57    if sig == signal.SIGINT:
     58        return "interrupt"
     59    if sig == signal.SIGQUIT:
     60        return "quit"
     61    if sig == signal.SIGILL:
     62        return "illegal instruction"
     63    if sig == signal.SIGABRT:
     64        return "abort"
     65    if sig == signal.SIGFPE:
     66        return "floating point exception"
     67    if sig == signal.SIGKILL:
     68        return "kill signal"
     69    if sig == signal.SIGSEGV:
     70        return "segmentation fault"
     71    if sig == signal.SIGPIPE:
     72        return "broken pipe"
     73    if sig == signal.SIGALRM:
     74        return "alarm"
     75    if sig == signal.SIGTERM:
     76        return "terminate"
     77    if sig == signal.SIGBUS:
     78        return "bus error"
     79    return "signal %s"%sig
    2280
    2381class DocTestReporter(SageObject):
    2482    """
     
    48106        self.postscript = dict(lines=[], cputime=0, walltime=0)
    49107        self.sources_completed = 0
    50108        self.stats = {}
    51         self.error_status = 0 # partially for backward compatibility
     109        self.error_status = 0
     110
     111    def report_head(self, source):
     112        """
     113        Return the "sage -t [options] file.py" line as string.
     114
     115        INPUT:
     116
     117        - ``source`` -- a source from :mod:`sage.doctest.sources`
     118
     119        EXAMPLES::
     120
     121            sage: from sage.doctest.reporting import DocTestReporter
     122            sage: from sage.doctest.control import DocTestController, DocTestDefaults
     123            sage: from sage.doctest.sources import FileDocTestSource
     124            sage: from sage.doctest.forker import SageDocTestRunner
     125            sage: filename = os.path.join(os.environ['SAGE_ROOT'],'devel','sage','sage','doctest','reporting.py')
     126            sage: FDS = FileDocTestSource(filename,True,False,set(['sage']),None)
     127            sage: DD = DocTestDefaults()
     128            sage: DC = DocTestController(DD, [filename])
     129            sage: DTR = DocTestReporter(DC)
     130            sage: print DTR.report_head(FDS)
     131            sage -t .../sage/doctest/reporting.py
     132
     133        The same with various options::
     134
     135            sage: DD.long = True
     136            sage: print DTR.report_head(FDS)
     137            sage -t --long .../sage/doctest/reporting.py
     138        """
     139        cmd = "sage -t"
     140        if self.controller.options.long:
     141            cmd += " --long"
     142        warnlong = self.controller.options.warn_long
     143        if warnlong is not None:
     144            cmd += " --warn-long"
     145            if warnlong != 1.0:
     146                cmd += " %.1f"%(warnlong)
     147        cmd += " " + source.printpath
     148        return cmd
    52149
    53150    def report(self, source, timeout, return_code, results, output):
    54151        """
    55152        Report on the result of running doctests on a given source.
    56153
     154        This doesn't print the :meth:`report_head`, which is assumed
     155        to be printed already.
     156
    57157        INPUT:
    58158
    59159        - ``source`` -- a source from :mod:`sage.doctest.sources`
     
    72172            :class:`sage.doctest.sources.DictAsObject` instance
    73173            storing timing data.
    74174
    75           - ``delayed_output`` -- delayed output to be printed now
    76 
    77175        - ``output`` -- a string, printed if there was some kind of
    78176          failure
    79177
     
    95193        You can report a timeout::
    96194
    97195            sage: DTR.report(FDS, True, 0, None, "Output so far...")
    98             sage -t .../sage/doctest/reporting.py
    99                 Timed out!
     196                Time out
    100197            ********************************************************************************
    101             Tests run before process froze:
     198            Tests run before process timed out:
    102199            Output so far...
    103200            ********************************************************************************
    104201            sage: DTR.stats
     
    106203
    107204        Or a process that returned a bad exit code::
    108205
    109             sage: DTR.report(FDS, False, 3, None, "Output before bad exit")
    110             sage -t .../sage/doctest/reporting.py
     206            sage: DTR.report(FDS, False, 3, None, "Output before trouble")
    111207                Bad exit: 3
    112208            ********************************************************************************
    113209            Tests run before process failed:
    114             Output before bad exit
     210            Output before trouble
     211            ********************************************************************************
     212            sage: DTR.stats
     213            {'sage.doctest.reporting': {'failed': True, 'walltime': 1000000.0}}
     214
     215        Or a process that segfaulted::
     216
     217            sage: import signal
     218            sage: DTR.report(FDS, False, -signal.SIGSEGV, None, "Output before trouble")
     219                Killed due to segmentation fault
     220            ********************************************************************************
     221            Tests run before process failed:
     222            Output before trouble
     223            ********************************************************************************
     224            sage: DTR.stats
     225            {'sage.doctest.reporting': {'failed': True, 'walltime': 1000000.0}}
     226
     227        Report a timeout with results and a ``SIGKILL``::
     228
     229            sage: DTR.report(FDS, True, -signal.SIGKILL, (1,None), "Output before trouble")
     230                Time out after testing finished (and interrupt failed)
     231            ********************************************************************************
     232            Tests run before process timed out:
     233            Output before trouble
     234            ********************************************************************************
     235            sage: DTR.stats
     236            {'sage.doctest.reporting': {'failed': True, 'walltime': 1000000.0}}
     237
     238        This is an internal error since results is None::
     239
     240            sage: DTR.report(FDS, False, 0, None, "All output")
     241                Error in doctesting framework (bad result returned)
     242            ********************************************************************************
     243            Tests run before error:
     244            All output
    115245            ********************************************************************************
    116246            sage: DTR.stats
    117247            {'sage.doctest.reporting': {'failed': True, 'walltime': 1000000.0}}
     
    119249        Or tell the user that everything succeeded::
    120250
    121251            sage: doctests, extras = FDS.create_doctests(globals())
    122             sage: runner = SageDocTestRunner(SageOutputChecker(), output = os.tmpfile(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
     252            sage: runner = SageDocTestRunner(SageOutputChecker(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
    123253            sage: Timer().start().stop().annotate(runner)
    124254            sage: D = DictAsObject({'err':None})
    125255            sage: runner.update_results(D)
    126256            0
    127             sage: DTR.report(FDS, False, 0, (sum([len(t.examples) for t in doctests]), D, ""), "Good tests")
    128             sage -t .../doctest/reporting.py
     257            sage: DTR.report(FDS, False, 0, (sum([len(t.examples) for t in doctests]), D), "Good tests")
    129258                [... tests, 0.0 s]
    130259            sage: DTR.stats
    131260            {'sage.doctest.reporting': {'walltime': ...}}
     
    135264            sage: runner.failures = 1
    136265            sage: runner.update_results(D)
    137266            1
    138             sage: DTR.report(FDS, False, 0, (sum([len(t.examples) for t in doctests]), D, ""), "Doctest output including the failure...")
    139             sage -t .../doctest/reporting.py
     267            sage: DTR.report(FDS, False, 0, (sum([len(t.examples) for t in doctests]), D), "Doctest output including the failure...")
    140268                [... tests, 1 failure, 0.0 s]
    141269        """
    142         log = self.controller.log
    143         postscript = self.postscript
    144         stats = self.stats
    145270        try:
     271            log = self.controller.log
     272            postscript = self.postscript
     273            stats = self.stats
    146274            basename = source.basename
    147             if self.controller.options.long:
    148                 islong = "--long "
    149             else:
    150                 islong = ""
    151             warnlong = self.controller.options.warn_long
    152             if warnlong is None:
    153                 warnlong = ""
    154             elif warnlong == 1.0:
    155                 warnlong = "--warn-long "
    156             else:
    157                 warnlong = "--warn-long %.1f "%(warnlong)
    158             cmd = "sage -t %s%s%s"%(islong, warnlong, source.printpath)
    159             log(cmd)
     275            cmd = self.report_head(source)
     276
     277            try:
     278                ntests, result_dict = results
     279            except (TypeError, ValueError):
     280                ntests = 0
     281                result_dict = DictAsObject(dict(err='badresult'))
     282
    160283            if timeout:
    161                 log("    Timed out!\n%s\nTests run before process froze:"%("*"*80))
     284                fail_msg = "Time out"
     285                if ntests > 0:
     286                    fail_msg += " after testing finished"
     287                if return_code > 0:
     288                    fail_msg += " (with error after interrupt)"
     289                elif return_code < 0:
     290                    sig = -return_code
     291                    if sig == signal.SIGKILL:
     292                        fail_msg += " (and interrupt failed)"
     293                    else:
     294                        fail_msg += " (with %s after interrupt)"%signal_name(-return_code)
     295                log("    %s\n%s\nTests run before process timed out:"%(fail_msg, "*"*80))
    162296                log(output)
    163297                log("*"*80)
    164                 postscript['lines'].append(cmd + " # Time out")
     298                postscript['lines'].append(cmd + "  # %s"%fail_msg)
    165299                stats[basename] = dict(failed=True, walltime=1e6)
    166                 self.error_status |= 64
     300                self.error_status |= 4
    167301            elif return_code:
    168                 log("    Bad exit: %s\n%s\nTests run before process failed:"%(return_code,"*"*80))
     302                if return_code > 0:
     303                    fail_msg = "Bad exit: %s"%return_code
     304                else:
     305                    fail_msg = "Killed due to %s"%signal_name(-return_code)
     306                if ntests > 0:
     307                    fail_msg += " after testing finished"
     308                log("    %s\n%s\nTests run before process failed:"%(fail_msg,"*"*80))
    169309                log(output)
    170310                log("*"*80)
    171                 postscript['lines'].append(cmd + " # Bad exit: %s" % return_code)
     311                postscript['lines'].append(cmd + "  # %s" % fail_msg)
    172312                stats[basename] = dict(failed=True, walltime=1e6)
    173                 self.error_status |= 4
    174             elif results is None:
    175                 log("    Error in doctesting framework!\n%s\nTests run before error:"%("*"*80))
    176                 log(output)
    177                 log("*"*80)
    178                 stats[basename] = dict(failed=True, walltime=1e6)
    179                 postscript['lines'].append(cmd + " # Unhandled doctest exception")
    180                 self.error_status |= 8
     313                self.error_status |= (8 if return_code > 0 else 16)
    181314            else:
    182                 ntests, result_dict, delayed_output = results
    183315                if hasattr(result_dict, 'walltime') and hasattr(result_dict.walltime, '__len__') and len(result_dict.walltime) > 0:
    184316                    wall = sum(result_dict.walltime) / len(result_dict.walltime)
    185317                else:
     
    188320                    cpu = sum(result_dict.cputime) / len(result_dict.cputime)
    189321                else:
    190322                    cpu = 1e6
    191                 if result_dict.err == 'file':
    192                     log("    File not found!")
    193                     postscript['lines'].append(cmd + " # File not found")
    194                     self.error_status |= 1
     323                if result_dict.err == 'badresult':
     324                    log("    Error in doctesting framework (bad result returned)\n%s\nTests run before error:"%("*"*80))
     325                    log(output)
     326                    log("*"*80)
     327                    postscript['lines'].append(cmd + "  # Testing error: bad result")
     328                    self.error_status |= 64
    195329                elif result_dict.err == 'noresult':
    196330                    log("    Error in doctesting framework (no result returned)\n%s\nTests run before error:"%("*"*80))
    197331                    log(output)
    198332                    log("*"*80)
    199                     postscript['lines'].append(cmd + " # Testing error: no result returned")
    200                     self.error_status |= 8
    201                 elif result_dict.err == 'ctlC':
    202                     log("    Unexpected KeyboardInterrupt raised in file\n%s\nTests run before interrupt:"%("*"*80))
    203                     log(output)
    204                     log("*"*80)
    205                     postscript['lines'].append(cmd + " # Unhandled KeyboardInterrupt")
    206                     stats[basename] = dict(failed=True, walltime = wall)
    207                     self.error_status |= 8
     333                    postscript['lines'].append(cmd + "  # Testing error: no result")
     334                    self.error_status |= 64
    208335                elif result_dict.err == 'tab':
    209336                    if len(result_dict.tab_linenos) > 5:
    210337                        result_dict.tab_linenos[3:-1] = "..."
     
    212339                    if len(result_dict.tab_linenos) > 1:
    213340                        tabs = "s" + tabs
    214341                    log("    Error: TAB character found at line%s"%(tabs))
    215                     postscript['lines'].append(cmd + " # Tab character found")
     342                    postscript['lines'].append(cmd + "  # Tab character found")
    216343                    self.error_status |= 32
    217                 elif result_dict.err is True:
     344                elif result_dict.err is not None:
    218345                    # This case should not occur
    219                     log("    Error in doctesting framework")
    220                     postscript['lines'].append(cmd + " # Unhandled doctest exception")
    221                     self.error_status |= 8
    222                 elif result_dict.err is not None:
     346                    if result_dict.err is True:
     347                        fail_msg = "Error in doctesting framework"
     348                    else:
     349                        if hasattr(result_dict.err, '__name__'):
     350                            err = result_dict.err.__name__
     351                        else:
     352                            err = repr(result_dict.err)
     353                        fail_msg = "%s in doctesting framework"%err
     354
     355                    log("    %s\n%s"%(fail_msg, "*"*80))
     356                    if output:
     357                        log("Tests run before doctest exception:\n" + output)
     358                        log("*"*80)
     359                    postscript['lines'].append(cmd + "  # %s"%fail_msg)
    223360                    if hasattr(result_dict, 'tb'):
    224361                        log(result_dict.tb)
    225                     if hasattr(result_dict.err, '__name__'):
    226                         err = result_dict.err.__name__
    227                     else:
    228                         err = repr(result_dict.err)
    229                     postscript['lines'].append(cmd + " # %s in loading"%(err))
    230362                    if hasattr(result_dict, 'walltime'):
    231363                        stats[basename] = dict(failed=True, walltime=wall)
    232364                    else:
    233365                        stats[basename] = dict(failed=True, walltime=1e6)
    234                     self.error_status |= 16
     366                    self.error_status |= 64
    235367                if result_dict.err is None or result_dict.err == 'tab':
    236368                    f = result_dict.failures
    237369                    if f:
    238                         postscript['lines'].append(cmd + " # %s failed" % (count_noun(f, "doctest")))
    239                         self.error_status |= 128
     370                        postscript['lines'].append(cmd + "  # %s failed" % (count_noun(f, "doctest")))
     371                        self.error_status |= 1
    240372                    if f or result_dict.err == 'tab':
    241373                        stats[basename] = dict(failed=True, walltime=wall)
    242374                    else:
     
    244376                    postscript['cputime'] += cpu
    245377                    postscript['walltime'] += wall
    246378
    247                     if delayed_output:
    248                         if delayed_output[-1] == '\n':
    249                             delayed_output = delayed_output[:-1]
    250                         log(delayed_output)
    251379                    log("    [%s, %s%.1f s]" % (count_noun(ntests, "test"), "%s, "%(count_noun(f, "failure")) if f else "", wall))
    252380            self.sources_completed += 1
    253381
     
    279407        Now we pretend to run some doctests::
    280408
    281409            sage: DTR.report(FDS, True, 0, None, "Output so far...")
    282             sage -t .../sage/doctest/reporting.py
    283                 Timed out!
     410                Time out
    284411            ********************************************************************************
    285             Tests run before process froze:
     412            Tests run before process timed out:
    286413            Output so far...
    287414            ********************************************************************************
    288415            sage: DTR.report(FDS, False, 3, None, "Output before bad exit")
    289             sage -t .../sage/doctest/reporting.py
    290416                Bad exit: 3
    291417            ********************************************************************************
    292418            Tests run before process failed:
    293419            Output before bad exit
    294420            ********************************************************************************
    295421            sage: doctests, extras = FDS.create_doctests(globals())
    296             sage: runner = SageDocTestRunner(SageOutputChecker(), output = os.tmpfile(), verbose=False, sage_options=DD,optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
     422            sage: runner = SageDocTestRunner(SageOutputChecker(), verbose=False, sage_options=DD,optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
    297423            sage: t = Timer().start().stop()
    298424            sage: t.annotate(runner)
    299425            sage: DC.timer = t
    300426            sage: D = DictAsObject({'err':None})
    301427            sage: runner.update_results(D)
    302428            0
    303             sage: DTR.report(FDS, False, 0, (sum([len(t.examples) for t in doctests]), D, ""), "Good tests")
    304             sage -t .../doctest/reporting.py
     429            sage: DTR.report(FDS, False, 0, (sum([len(t.examples) for t in doctests]), D), "Good tests")
    305430                [... tests, 0.0 s]
    306431            sage: runner.failures = 1
    307432            sage: runner.update_results(D)
    308433            1
    309             sage: DTR.report(FDS, False, 0, (sum([len(t.examples) for t in doctests]), D, ""), "Doctest output including the failure...")
    310             sage -t .../doctest/reporting.py
     434            sage: DTR.report(FDS, False, 0, (sum([len(t.examples) for t in doctests]), D), "Doctest output including the failure...")
    311435                [... tests, 1 failure, 0.0 s]
    312436
    313437        Now we can show the output of finalize::
     
    315439            sage: DC.sources = [None] * 4 # to fool the finalize method
    316440            sage: DTR.finalize()
    317441            ------------------------------------------------------------------------
    318             sage -t .../sage/doctest/reporting.py # Time out
    319             sage -t .../sage/doctest/reporting.py # Bad exit: 3
    320             sage -t .../sage/doctest/reporting.py # 1 doctest failed
     442            sage -t .../sage/doctest/reporting.py  # Time out
     443            sage -t .../sage/doctest/reporting.py  # Bad exit: 3
     444            sage -t .../sage/doctest/reporting.py  # 1 doctest failed
    321445            ------------------------------------------------------------------------
    322446            Total time for all tests: 0.0 seconds
    323447                cpu time: 0.0 seconds
     
    330454            sage: DTR.finalize()
    331455            <BLANKLINE>
    332456            ------------------------------------------------------------------------
    333             sage -t .../sage/doctest/reporting.py # Time out
    334             sage -t .../sage/doctest/reporting.py # Bad exit: 3
    335             sage -t .../sage/doctest/reporting.py # 1 doctest failed
     457            sage -t .../sage/doctest/reporting.py  # Time out
     458            sage -t .../sage/doctest/reporting.py  # Bad exit: 3
     459            sage -t .../sage/doctest/reporting.py  # 1 doctest failed
    336460            Doctests interrupted: 4/6 files tested
    337461            ------------------------------------------------------------------------
    338462            Total time for all tests: 0.0 seconds
     
    343467        postscript = self.postscript
    344468        if self.sources_completed < len(self.controller.sources) * self.controller.options.global_iterations:
    345469            postscript['lines'].append("Doctests interrupted: %s/%s files tested"%(self.sources_completed, len(self.controller.sources)))
    346             self.error_status |= 2
     470            self.error_status |= 128
    347471        elif not postscript['lines']:
    348472            postscript['lines'].append("All tests passed!")
    349473        log('-' * 72)
  • sage/doctest/sources.py

    diff --git a/sage/doctest/sources.py b/sage/doctest/sources.py
    a b  
    4747
    4848# For testing that enough doctests are created
    4949sagestart = re.compile(r"^\s*(>>> |sage: )\s*[^#\s]")
    50 untested = re.compile("(not implemented|not tested|known bug)")
     50untested = re.compile("(not implemented|not tested)")
     51
    5152
    5253def get_basename(path):
    5354    """
     
    9697
    9798    INPUT:
    9899
    99     - ``long`` -- whether to execute tests marked as #long
     100    - ``long`` -- whether to execute tests marked as ``# long time``
    100101
    101102    - ``optional`` -- either True or a set of optional tags to execute
    102103
     
    165166
    166167            sage: from sage.doctest.sources import FileDocTestSource
    167168            sage: from sage.doctest.parsing import SageDocTestParser
    168             sage: from sage.doctest.util import NestedName
    169169            sage: import os
    170170            sage: filename = os.path.join(os.environ['SAGE_ROOT'],'devel','sage','sage','doctest','util.py')
    171171            sage: FDS = FileDocTestSource(filename,True,False,set(['sage']),None)
     
    179179        """
    180180        docstring = "".join(doc)
    181181        new_doctests = self.parse_docstring(docstring, namespace, start)
    182         #print "New tests! %s"%len(new_doctests)
    183182        for dt in new_doctests:
    184183            if len(dt.examples) > 0 and not (hasattr(dt.examples[-1],'sage_source')
    185184                                             and dt.examples[-1].sage_source == "sig_on_count()\n"):
    186                 sigon = doctest.Example("sig_on_count()\n", "0\n", lineno=100000 + len(doc))
     185                sigon = doctest.Example("sig_on_count()\n", "0\n")
    187186                sigon.sage_source = "sig_on_count()\n"
    188187                dt.examples.append(sigon)
    189188            doctests.append(dt)
     
    311310    - ``source`` -- a string, giving the source code to be parsed for
    312311      doctests.
    313312
    314     - ``long`` -- whether to execute tests marked as #long
     313    - ``long`` -- whether to execute tests marked as ``# long time``
    315314
    316315    - ``optional`` -- either True or a set of optional tags to execute
    317316
     
    417416    - ``force_lib`` -- bool, whether this file shoule be considered
    418417      part of the Sage library
    419418
    420     - ``long`` -- whether to execute tests marked as #long
     419    - ``long`` -- whether to execute tests marked as ``# long time``
    421420
    422421    - ``optional`` -- either True or a set of optional tags to execute
    423422
     
    472471        EXAMPLES::
    473472
    474473            sage: from sage.doctest.sources import FileDocTestSource
    475             sage: import os
    476             sage: filename = os.path.join(SAGE_TMP, 'test.py')
     474            sage: filename = tmp_filename(ext=".py")
    477475            sage: s = "'''\n    sage: 2 + 2\n    4\n'''"
    478             sage: with open(filename, 'w') as F:
    479             ....:     F.write(s)
     476            sage: open(filename, 'w').write(s)
    480477            sage: FDS = FileDocTestSource(filename, False, False, set(['sage']), False)
    481478            sage: for n, line in FDS:
    482479            ....:     print n, line,
     
    629626        self.qualified_name = NestedName(self.basename)
    630627        return self._create_doctests(namespace)
    631628
    632     def _test_enough_doctests(self, check_extras = True, verbose = True):
     629    def _test_enough_doctests(self, check_extras=True, verbose=True):
    633630        """
    634631        This function checks to see that the doctests are not getting
    635632        unexpectedly skipped.  It uses a different (and simpler) code
     
    649646        TESTS::
    650647
    651648            sage: from sage.doctest.sources import FileDocTestSource
    652             sage: sage_loc = os.path.join(os.environ['SAGE_ROOT'],'devel','sage','sage')
    653             sage: doc_loc = os.path.join(os.environ['SAGE_ROOT'],'devel','sage','doc')
     649            sage: os.chdir(os.path.join(os.environ['SAGE_ROOT'],'devel','sage'))
    654650            sage: import itertools
    655             sage: for path, dirs, files in itertools.chain(os.walk(sage_loc), os.walk(doc_loc)): # long time
     651            sage: for path, dirs, files in itertools.chain(os.walk('sage'), os.walk('doc')): # long time
    656652            ....:     path = os.path.relpath(path)
     653            ....:     dirs.sort(); files.sort()
    657654            ....:     for F in files:
    658655            ....:         _, ext = os.path.splitext(F)
    659             ....:         if ext in ('.py', '.pyx', '.sage', '.spyx', '.rst', '.tex'):
     656            ....:         if ext in ('.py', '.pyx', '.sage', '.spyx', '.rst'):
    660657            ....:             filename = os.path.join(path, F)
    661658            ....:             FDS = FileDocTestSource(filename, True, True, True, False)
    662659            ....:             FDS._test_enough_doctests(verbose=False)
    663             There are 3 unexpected tests being run in .../sage/doctest/parsing.py
    664             There are 1 tests in .../sage/ext/c_lib.pyx that are not being run
    665             There are 2 tests in .../sage/server/notebook/worksheet.py that are not being run
    666             There are 5 tests in .../doc/en/tutorial/interfaces.rst that are not being run
     660            There are 3 unexpected tests being run in sage/doctest/parsing.py
     661            There are 1 tests in sage/ext/c_lib.pyx that are not being run
     662            There are 9 tests in sage/graphs/graph_plot.py that are not being run
     663            There are 2 tests in sage/server/notebook/worksheet.py that are not being run
     664            doctest:229: UnicodeWarning: Unicode equal comparison failed to convert both arguments to Unicode - interpreting them as being unequal
    667665        """
    668666        expected = []
    669667        rest = isinstance(self, RestSource)
     
    691689                        in_block = True
    692690                        starting_indent = whitespace.match(line).end()
    693691                last_line = line
    694             ## print (not rest or in_block), bool(sagestart.match(line)), ((rest and skipping) or untested.search(line.lower())), line
    695692            if (not rest or in_block) and sagestart.match(line) and not ((rest and skipping) or untested.search(line.lower())):
    696693                expected.append(lineno+1)
    697694        actual = []
    698695        tests, _ = self.create_doctests({})
    699696        for dt in tests:
    700697            if len(dt.examples) > 0:
    701                 for ex in dt.examples[:-1]: # the last entry is a sig_on()
     698                for ex in dt.examples[:-1]: # the last entry is a sig_on_count()
    702699                    actual.append(dt.lineno + ex.lineno + 1)
    703700        shortfall = sorted(list(set(expected).difference(set(actual))))
    704701        extras = sorted(list(set(actual).difference(set(expected))))
  • sage/doctest/util.py

    diff --git a/sage/doctest/util.py b/sage/doctest/util.py
    a b  
    1212#                          William Stein <wstein@gmail.com>
    1313#
    1414#  Distributed under the terms of the GNU General Public License (GPL)
    15 #
     15#  as published by the Free Software Foundation; either version 2 of
     16#  the License, or (at your option) any later version.
    1617#                  http://www.gnu.org/licenses/
    1718#*****************************************************************************
    1819
    19 import re
     20
    2021from sage.misc.misc import walltime, cputime
    2122
    2223def count_noun(number, noun, plural=None, pad_number=False, pad_noun=False):
     
    5657            plural = "%ss"%(noun)
    5758        return "%s %s"%(number_str, plural)
    5859
     60
     61def dict_difference(self, other):
     62    """
     63    Return a dict with all key-value pairs occuring in ``self`` but not
     64    in ``other``.
     65
     66    EXAMPLES::
     67
     68        sage: from sage.doctest.util import dict_difference
     69        sage: d1 = {1: 'a', 2: 'b', 3: 'c'}
     70        sage: d2 = {1: 'a', 2: 'x', 4: 'c'}
     71        sage: dict_difference(d2, d1)
     72        {2: 'x', 4: 'c'}
     73
     74    ::
     75
     76        sage: from sage.doctest.control import DocTestDefaults
     77        sage: D1 = DocTestDefaults()
     78        sage: D2 = DocTestDefaults(foobar="hello", timeout=100)
     79        sage: dict_difference(D2.__dict__, D1.__dict__)
     80        {'foobar': 'hello', 'timeout': 100}
     81    """
     82    D = dict()
     83    for (k,v) in self.iteritems():
     84        try:
     85            if other[k] == v:
     86                continue
     87        except KeyError:
     88            pass
     89        D[k] = v
     90    return D
     91
     92
    5993class Timer:
    6094    """
    6195    A simple timer.
     
    435469
    436470    def __cmp__(self, other):
    437471        """
    438         Comparison ist just comparison of the underlying lists.
     472        Comparison is just comparison of the underlying lists.
    439473
    440474        EXAMPLES::
    441475
  • sage/tests/cmdline.py

    diff --git a/sage/tests/cmdline.py b/sage/tests/cmdline.py
    a b  
    5656
    5757
    5858def test_executable(args, input="", timeout=50.0, cwd=None):
    59     """
     59    r"""
    6060    Run the program defined by ``args`` using the string ``input`` on
    6161    the standard input.
    6262
     
    294294    Testing ``sage --preparse FILE`` and ``sage -t FILE``.  First create
    295295    a file and preparse it::
    296296
    297         sage: s = '\"\"\"\nThis is a test file.\n\"\"\"\ndef my_add(a,b):\n    \"\"\"\n    Add a to b.\n\n        EXAMPLES::\n\n            sage: my_add(2,2)\n            4\n        \"\"\"\n    return a+b\n'
     297        sage: s = "'''\nThis is a test file.\n'''\ndef my_add(a,b):\n    '''\n    Add a to b.\n\n        EXAMPLES::\n\n            sage: my_add(2,2)\n            4\n        '''\n    return a + b\n"
    298298        sage: script = os.path.join(tmp_dir(), 'my_script.sage')
    299299        sage: script_py = script[:-5] + '.py'
    300300        sage: F = open(script, 'w')
     
    319319        sage: out.find("All tests passed!") >= 0
    320320        True
    321321
    322     Now for a file which should fail tests.  Run this test with
    323     SAGE_TESTDIR equal to a temporary directory, because failed doctests
    324     leave files lying around in SAGE_TESTDIR::
     322    Now for a file which should fail tests::
    325323
    326324        sage: s = s.replace('4', '5') # (2+2 != 5)
    327325        sage: F = open(script, 'w')
    328326        sage: F.write(s)
    329327        sage: F.close()
    330         sage: OLD_TESTDIR = os.environ['SAGE_TESTDIR']
    331         sage: os.environ['SAGE_TESTDIR'] = tmp_dir()
    332328        sage: (out, err, ret) = test_executable(["sage", "-t", script])
    333329        sage: ret
    334         128
     330        1
    335331        sage: out.find("1 item had failures:") >= 0
    336332        True
    337         sage: os.environ['SAGE_TESTDIR'] = OLD_TESTDIR  # just in case
     333
     334    Test ``sage -t --debug -p 2`` on a ReST file, the ``-p 2`` should
     335    be ignored. In Pdb, we run the ``help`` command::
     336
     337        sage: s = "::\n\n    sage: assert True == False\n    sage: 2 + 2\n    5"
     338        sage: script = tmp_filename(ext='.rst')
     339        sage: F = open(script, 'w')
     340        sage: F.write(s)
     341        sage: F.close()
     342        sage: (out, err, ret) = test_executable(["sage", "-t", "--debug", "-p", "2", script], "help")
     343        sage: print out
     344        Debugging requires single-threaded operation, setting number of threads to 1.
     345        Running doctests with ID...
     346        Doctesting 1 file.
     347        sage -t ...
     348        **********************************************************************
     349        File "...", line 3, in ...
     350        Failed example:
     351            assert True == False
     352        Exception raised:
     353            Traceback (most recent call last):
     354            ...
     355            AssertionError
     356        > <doctest ...>(1)<module>()
     357        -> assert True == False
     358        (Pdb)
     359        Documented commands (type help <topic>):
     360        ========================================
     361        ...
     362        **********************************************************************
     363        File "...", line 4, in ...
     364        Failed example:
     365            2 + 2
     366        Expected:
     367            5
     368        Got:
     369            4
     370        **********************************************************************
     371        1 item had failures:
     372           2 of   3 in ...
     373            [2 tests, 2 failures, ...]
     374        ...
     375        sage: ret
     376        1
    338377
    339378    Check that Sage refuses to run doctests from a directory whose
    340379    permissions are too loose.  We create a world-writable directory