Opened 4 years ago

Closed 4 years ago

Last modified 4 years ago

#25270 closed enhancement (fixed)

Add option to only run short doctests

Reported by: Julian Rüth Owned by:
Priority: minor Milestone: sage-8.5
Component: doctest framework Keywords:
Cc: Erik Bray, Nicolas M. Thiéry, David Roe Merged in:
Authors: Julian Rüth Reviewers: Erik Bray
Report Upstream: N/A Work issues: is the patchbot happy?
Branch: a4614ab (Commits, GitHub, GitLab) Commit:
Dependencies: Stopgaps:

Status badges

Description (last modified by Julian Rüth)

The attached picture shows how many modules (horizontal) you can run in how many CPU minutes (vertical). So, for example, in 40 CPU minutes (i.e., 10 wall minutes on my laptop) I can run all the doctests in 80% of all Sage modules. In 4 CPU minutes, I can doctest 50% of all Sage modules.

This ticket implements a --short [SECONDS] switch which runs as many doctests as possible (from the top of each module) in SECONDS (default 300).

This gives us a quick way to check that a change did not break things too terribly. For example, when I work on p-adics, I would probably do: sage -tp --short 30 src/sage/rings/padics frequently. Once I am happy with my changes, I could do sage -tp --short src/sage/rings and a final sage -tp --short --all before I leave the rest to the patchbot.

Here is an example:

> sage -tp --short 5 src/sage/rings/padics/*.py
Doctesting 19 files using 4 threads.
sage -t src/sage/rings/padics/padic_base_leaves.py
    [14% of tests run, 1.31 s]
sage -t src/sage/rings/padics/factory.py
    [29% of tests run, 1.31 s]
sage -t src/sage/rings/padics/lattice_precision.py
    [43% of tests run, 1.00 s]
sage -t src/sage/rings/padics/padic_valuation.py
    [4% of tests run, 2.80 s]
sage -t src/sage/rings/padics/padic_base_generic.py
    [95% of tests run, 1.72 s]
sage -t src/sage/rings/padics/local_generic.py
    [1% of tests run, 0.73 s]
sage -t src/sage/rings/padics/padic_extension_generic.py
    [5% of tests run, 0.77 s]
sage -t src/sage/rings/padics/padic_lattice_element.py
    [2% of tests run, 0.78 s]
sage -t src/sage/rings/padics/generic_nodes.py
    [1% of tests run, 0.75 s]
sage -t src/sage/rings/padics/padic_generic.py
    [1% of tests run, 0.73 s]
sage -t src/sage/rings/padics/unramified_extension_generic.py
    [2% of tests run, 0.43 s]
sage -t src/sage/rings/padics/tutorial.py
    [4% of tests run, 0.70 s]
sage -t src/sage/rings/padics/tests.py
    [0% of tests run, 0.00 s]
sage -t src/sage/rings/padics/eisenstein_extension_generic.py
    [7% of tests run, 0.80 s]
sage -t src/sage/rings/padics/misc.py
    [6% of tests run, 0.78 s]
sage -t src/sage/rings/padics/precision_error.py
    [0 tests, 0.00 s]
sage -t src/sage/rings/padics/all.py
    [0 tests, 0.00 s]
sage -t src/sage/rings/padics/__init__.py
    [0 tests, 0.00 s]
sage -t src/sage/rings/padics/padic_extension_leaves.py
    [10% of tests run, 6.54 s]
----------------------------------------------------------------------
All tests passed!
----------------------------------------------------------------------
Total time for all tests: 6.6 seconds
    cpu time: 20.0 seconds
    cumulative wall time: 21.1 seconds

Attachments (1)

bar.png (14.6 KB) - added by Julian Rüth 4 years ago.

Download all attachments as: .zip

Change History (68)

Changed 4 years ago by Julian Rüth

Attachment: bar.png added

comment:1 Changed 4 years ago by Julian Rüth

Description: modified (diff)

comment:2 Changed 4 years ago by Julian Rüth

Cc: Erik Bray Nicolas M. Thiéry David Roe added

comment:3 Changed 4 years ago by Julian Rüth

Summary: Add option to only run --short doctestsAdd option to only run short doctests

comment:4 Changed 4 years ago by Julian Rüth

I have a first prototype now. If I set it to try to finish in 30s walltime and run on src/sage/rings/padics, it does skip tests in only 4 files (here reported as failures at the moment):

sage -t ../rings/padics/padic_base_leaves.py  # 125 doctests failed
sage -t ../rings/padics/padic_lattice_element.py  # 303 doctests failed
sage -t ../rings/padics/padic_extension_leaves.py  # 72 doctests failed
sage -t ../rings/padics/padic_generic_element.pyx  # 172 doctests failed
----------------------------------------------------------------------
Total time for all tests: 35.8 seconds

As an extreme example, if let it test everything in src/ in two minutes, it manages to finish within four minutes (because it does not actually abort any doctest line once it started) and runs 314607 docstring lines and skips 361692, so it skips roughly 50%.

Last edited 4 years ago by Julian Rüth (previous) (diff)

comment:5 Changed 4 years ago by Julian Rüth

Branch: u/saraedum/25270

comment:6 Changed 4 years ago by Julian Rüth

Authors: Julian Rüth
Commit: d0f98ba118a581f2a23c3c753e4dfe9cec5288a6
Description: modified (diff)

New commits:

d0f98baImplement --short switch

comment:7 Changed 4 years ago by Julian Rüth

Description: modified (diff)

comment:8 Changed 4 years ago by Julian Rüth

Description: modified (diff)

comment:9 Changed 4 years ago by Julian Rüth

Work issues: needs doctests

I still need some doctests for this but if somebody already wants to comment on this, I would be very happy about some feedback.

Somehow my counting is off quite a bit. I am not entirely sure what's the problem.

Last edited 4 years ago by Julian Rüth (previous) (diff)

comment:10 Changed 4 years ago by Julian Rüth

Description: modified (diff)

comment:11 Changed 4 years ago by Julian Rüth

Status: newneeds_review
Work issues: needs doctestsneeds doctests, is the patchbot happy?

comment:12 Changed 4 years ago by Julian Rüth

I am quite unhappy with the spaghetti code that I added here but I don't really see a much better way. I have a feeling that we cramped a lot of features already into Python's doctesting framework and that it was never meant to be extended like that. A proper plugin system would have been cool but I guess it's too late for that ;)

comment:13 Changed 4 years ago by git

Commit: d0f98ba118a581f2a23c3c753e4dfe9cec5288a64c8639d3a736c61e3798de8512ae7c4df2d915d5

Branch pushed to git repo; I updated commit sha1. New commits:

4c8639dReport relative number of tests run in --short runs

comment:14 Changed 4 years ago by Erik Bray

Needs to be rebased it looks like. I can't wait to see this working though, and if I have some ideas how to improve the implementation I'll give them.

comment:15 Changed 4 years ago by git

Commit: 4c8639d3a736c61e3798de8512ae7c4df2d915d5915d8e6c2d7700b366dc773aed36e2c336f0e9b3

Branch pushed to git repo; I updated commit sha1. New commits:

915d8e6Merge develop into 25270

comment:16 Changed 4 years ago by Julian Rüth

Ok. I rebased this.

comment:17 Changed 4 years ago by Erik Bray

Reviewers: Erik Bray
Status: needs_reviewpositive_review

I wish we also had a way to prioritize tests. E.g. we could mark a test as # important and ensure all such tests get run first. That could be added later though.

comment:18 Changed 4 years ago by git

Commit: 915d8e6c2d7700b366dc773aed36e2c336f0e9b36c9c2ceb2112eba751ffdb0fbe583ff80734509c
Status: positive_reviewneeds_review

Branch pushed to git repo; I updated commit sha1 and set ticket back to needs_review. New commits:

6c9c2ceMerge remote-tracking branch 'trac/develop' into 25270

comment:19 Changed 4 years ago by Julian Rüth

Work issues: needs doctests, is the patchbot happy?is the patchbot happy ⇒ positive review

Rebased again. Somehow the patchbots fail to build this, probably they are broken atm.

comment:20 Changed 4 years ago by Erik Bray

My patchbot Ubuntu/18.04/x86_64/3.13.0-123-generic/sagemath-patchbot-docker was broken for a few days due to running out of disk space. It should be working now though.

comment:21 Changed 4 years ago by Timo Kaufmann

This will only work if the full testsuite is run at least once and allowed to save state right?

I'd love something like this for distribution CI (testing weather or not a dependency update breaks sage), but if thats the case it couldn't be used for that. Something like #important would be good in that case.

comment:22 in reply to:  21 Changed 4 years ago by Julian Rüth

Replying to gh-timokau:

This will only work if the full testsuite is run at least once and allowed to save state right?

No. The changes proposed here do not rely on saved state.

comment:23 Changed 4 years ago by Timo Kaufmann

Thats great! The code is a bit hard to read without context and I don't want to dig too deeply. How does it determine which tests to skip then? Just allocate equal time to each file and abort remaining tests if the time budged is used up?

comment:24 Changed 4 years ago by Julian Rüth

Yes. It allocates equal time and starts testing from the top.

comment:25 Changed 4 years ago by John Palmieri

This also needs to be documented in src/doc/en/reference/repl/options.rst.

comment:26 Changed 4 years ago by John Palmieri

Does the [SECONDS] argument refer to the total time for testing, or the time for each file? When I ran sage --tp --short 15 src/sage, it spent much less than 15 seconds on each file before giving up.

comment:27 Changed 4 years ago by Julian Rüth

Status: needs_reviewneeds_work
Work issues: is the patchbot happy ⇒ positive reviewis the patchbot happy ⇒ positive review + documentation

The [SECONDS] are the total amount of time.

comment:28 Changed 4 years ago by John Palmieri

I am getting a doctest failure from sage -tp --short 600 src/sage/:

sage -t src/sage/doctest/reporting.py
**********************************************************************
File "src/sage/doctest/reporting.py", line 324, in sage.doctest.reporting.DocTestReporter.report
Failed example:
    DTR.report(FDS, False, 0, (sum([len(t.examples) for t in doctests]), D), "Good tests")
Expected:
        1 unlabeled test not run
        4 long tests not run
        5 magma tests not run
        2 other tests skipped
        [... tests, ... s]
Got:
        1 unlabeled test not run
        4 long tests not run
        5 magma tests not run
        2 not tested tests not run
        0 tests not run because we ran out of time
        [126 tests, 0.00 s]
**********************************************************************
File "src/sage/doctest/reporting.py", line 350, in sage.doctest.reporting.DocTestReporter.report
Failed example:
    DTR.report(FDS, False, 0, (sum([len(t.examples) for t in doctests]), D), "Good tests")
Expected nothing
Got:
        [126 tests, 0.00 s]
**********************************************************************
1 item had failures:
   2 of  57 in sage.doctest.reporting.DocTestReporter.report
    [120 tests, 2 failures, 0.54 s]

comment:29 Changed 4 years ago by git

Commit: 6c9c2ceb2112eba751ffdb0fbe583ff80734509c8517278d26b913893d50258ff9179ea6845e55f6

Branch pushed to git repo; I updated commit sha1. New commits:

8517278Fix reporting doctest

comment:30 Changed 4 years ago by Julian Rüth

Status: needs_workneeds_review

New commits:

8517278Fix reporting doctest

comment:31 Changed 4 years ago by Erik Bray

Let's see what the patchbot says (if indeed I've actually managed to fix it...)

comment:32 Changed 4 years ago by Erik Bray

Got a few test failures in sage.doctest that seem relevant :)

comment:33 Changed 4 years ago by Erik Bray

Status: needs_reviewneeds_work

comment:34 Changed 4 years ago by git

Commit: 8517278d26b913893d50258ff9179ea6845e55f68d3bd2edf7810e812e5f4cb7ce92d8e598fc9f9a

Branch pushed to git repo; I updated commit sha1. New commits:

8d3bd2efixed doctests

comment:35 Changed 4 years ago by git

Commit: 8d3bd2edf7810e812e5f4cb7ce92d8e598fc9f9a4f1175738b99eb7533743719e0b2f1ea2392e922

Branch pushed to git repo; I updated commit sha1. New commits:

4f11757Add --short to options.rst

comment:36 Changed 4 years ago by Julian Rüth

Status: needs_workneeds_review
Work issues: is the patchbot happy ⇒ positive review + documentationis the patchbot happy ⇒ positive review

New commits:

8d3bd2efixed doctests
4f11757Add --short to options.rst

comment:37 Changed 4 years ago by Erik Bray

Still getting a failure:

sage -t --long src/sage/doctest/reporting.py
**********************************************************************
File "src/sage/doctest/reporting.py", line 351, in sage.doctest.reporting.DocTestReporter.report
Failed example:
    DTR.report(FDS, False, 0, (sum([len(t.examples) for t in doctests]), D), "Good tests")
Expected nothing
Got:
        [126 tests, 0.00 s]
**********************************************************************
1 item had failures:
   1 of  57 in sage.doctest.reporting.DocTestReporter.report
    [120 tests, 1 failure, 0.52 s]
----------------------------------------------------------------------
sage -t --long src/sage/doctest/reporting.py  # 1 doctest failed
----------------------------------------------------------------------

I've seen some cases before where the expected output was accidentally left off a doctest, and the doctest runner just ignored that, seemingly buggily, whereas fixing/changing things in the doctest runner made it start expecting output again. Could this be something like that?

comment:38 Changed 4 years ago by Erik Bray

Status: needs_reviewneeds_work

Maybe?

comment:39 Changed 4 years ago by Erik Bray

If my fast build machine weren't down I'd test to see if I could reproduce this manually.

comment:40 Changed 4 years ago by Erik Bray

Yeah, I was able to reproduce the test failure locally just running ./sage -t src/sage/doctest/reporting.py.

comment:41 Changed 4 years ago by Erik Bray

I think it's a legitimate regression, unlike my earlier guess. The failure is here:

        The only-errors mode does not output anything on success::

            sage: DD = DocTestDefaults(only_errors=True)
            sage: FDS = FileDocTestSource(filename, DD)
            sage: DC = DocTestController(DD, [filename])
            sage: DTR = DocTestReporter(DC)
            sage: doctests, extras = FDS.create_doctests(globals())
            sage: runner = SageDocTestRunner(SageOutputChecker(), verbose=False, sage_options=DD, optionflags=doctest.NORMALIZE_WHITESPACE|doctest.ELLIPSIS)
            sage: Timer().start().stop().annotate(runner)
            sage: D = DictAsObject({'err':None})
            sage: runner.update_results(D)
            0
            sage: DTR.report(FDS, False, 0, (sum([len(t.examples) for t in doctests]), D), "Good tests")

        However, failures are still output in the errors-only mode::

            sage: runner.failures = 1
            sage: runner.update_results(D)
            1
            sage: DTR.report(FDS, False, 0, (sum([len(t.examples) for t in doctests]), D), "Failed test")
                [... tests, 1 failure, ... s]

The intent of the test is that nothing should be output by DocTestRunner.report if it's in "only-errors mode" (a thing I didn't know existed), and there are no failures.

comment:42 Changed 4 years ago by git

Commit: 4f1175738b99eb7533743719e0b2f1ea2392e922fec87aad5e0f2f63be90b071aa3075e5c219b5a1

Branch pushed to git repo; I updated commit sha1. New commits:

1281cbfMerge remote-tracking branch 'trac/develop' into 25270
fec87aaHonor only_errors option

comment:43 Changed 4 years ago by Julian Rüth

Status: needs_workneeds_review

Ok. I had somehow removed the line about the only_errors flag. I put it back in.

comment:44 Changed 4 years ago by Erik Bray

Ok, positive review from me then pending results from a patchbot or two.

Mine were down all weekend so they'll probably need a day or 2 to get to it.

comment:45 Changed 4 years ago by git

Commit: fec87aad5e0f2f63be90b071aa3075e5c219b5a1829169ef330754ccfaa3f91d5725628fefef8fa5

Branch pushed to git repo; I updated commit sha1. New commits:

829169eMerge remote-tracking branch 'trac/develop' into 25270

comment:46 Changed 4 years ago by git

Commit: 829169ef330754ccfaa3f91d5725628fefef8fa537723128326405286df7e2bc05cfdf5e778fee78

Branch pushed to git repo; I updated commit sha1. New commits:

3772312Merge remote-tracking branch 'trac/develop' into HEAD

comment:47 Changed 4 years ago by Julian Rüth

Status: needs_reviewpositive_review
Work issues: is the patchbot happy ⇒ positive review

Finally, there was a happy patchbot based off 8.4.beta1 :)

comment:48 Changed 4 years ago by Julian Rüth

I am not sure that's the right approach here when looking at patchbot outputs but the patchbots are so flaky lately, that I just assume that "build fails" has nothing to do with this ticket.

comment:49 Changed 4 years ago by git

Commit: 37723128326405286df7e2bc05cfdf5e778fee78fd9c88272021cc40520638f30cf3dfa9d0d5a10f
Status: positive_reviewneeds_review

Branch pushed to git repo; I updated commit sha1 and set ticket back to needs_review. New commits:

bd63611Merge remote-tracking branch 'trac/develop' into 25270
fd9c882Merge remote-tracking branch 'trac/u/saraedum/25270' into 25270

comment:50 Changed 4 years ago by git

Commit: fd9c88272021cc40520638f30cf3dfa9d0d5a10f37723128326405286df7e2bc05cfdf5e778fee78

Branch pushed to git repo; I updated commit sha1. This was a forced push. New commits:

comment:51 Changed 4 years ago by Julian Rüth

Status: needs_reviewpositive_review

Sorry for this noise. I had pushed something to the wrong ticket. Reverted back to the reviewed state.

comment:52 Changed 4 years ago by Volker Braun

Status: positive_reviewneeds_work

Merge conflict

comment:53 Changed 4 years ago by Julian Rüth

Status: needs_workneeds_review
Work issues: is the patchbot happy ⇒ positive review

comment:54 Changed 4 years ago by git

Commit: 37723128326405286df7e2bc05cfdf5e778fee78cb73e0c0d85dd7da59b2a8b26d2341cb68348080

Branch pushed to git repo; I updated commit sha1. New commits:

cb73e0cMerge develop and 25270

comment:55 Changed 4 years ago by Julian Rüth

Status: needs_reviewneeds_work

comment:56 Changed 4 years ago by Julian Rüth

embray: I sometimes get

Error in atexit._run_exitfuncs:
Traceback (most recent call last):
  File "/home/sage/sage/local/lib/python2.7/atexit.py", line 24, in _run_exitfuncs
    func(*targs, **kargs)
  File "<doctest sage.cpython.atexit[2]>", line 2, in handler
NameError: global name 'print' is not defined
sage -t sage/src/sage/cpython/atexit.pyx
    NameError in doctesting framework
**********************************************************************
Tests run before doctest exception:
sage: import atexit ## line 54 ##
sage: from sage.cpython.atexit import restore_atexit ## line 55 ##
sage: def handler(*args, **kwargs):
    print((args, kwargs)) ## line 56 ##
sage: atexit.register(handler, 1, 2, c=3) ## line 58 ##
<function handler at 0x7f3ee18f41b8>

**********************************************************************
Traceback (most recent call last):
  File "/home/sage/sage/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 2426, in __call__
    break
  File "sage/cpython/atexit.pyx", line 143, in sage.cpython.atexit.restore_atexit.__exit__ (build/cythonized/sage/cpython/atexit.c:1497)
    atexit._run_exitfuncs()
  File "/home/sage/sage/local/lib/python2.7/atexit.py", line 24, in _run_exitfuncs
    func(*targs, **kargs)
  File "<doctest sage.cpython.atexit[2]>", line 2, in handler
NameError: global name 'print' is not defined

I guess this happens when the tests in atexit are only run partially and maybe some cleanup that is part of the doctests did not happen.

Since you're listed as the author of that file, any clue what's going on here?

comment:57 Changed 4 years ago by Erik Bray

Hmm--I think maybe, if nothing else, there should be a from __future__ import print_function in that module, which there currently is not. I'm not positive that that's the problem though. I'd have to try to reproduce it first.

comment:58 Changed 4 years ago by Erik Bray

Strange, though, since looking at sage.doctest.forker all doctests are supposed to be compiled as though from __future__ import print_function was present. Maybe, somehow, just including the required compile flags isn't enough to ensure that the print() function is in the globals?

comment:59 Changed 4 years ago by Erik Bray

For the atexit tests, does that happen if you test src/sage/cpython/atexit.pyx directly? Or does it only happen when running the full test suite with ./sage --short?

comment:60 Changed 4 years ago by Erik Bray

Milestone: sage-8.3sage-8.4

comment:61 Changed 4 years ago by git

Commit: cb73e0c0d85dd7da59b2a8b26d2341cb68348080b5b7b518ad5ab567ac6344b4e3a0133b4362420c

Branch pushed to git repo; I updated commit sha1. New commits:

b5b7b51Do not use print function in atexit

comment:62 Changed 4 years ago by Julian Rüth

embray, I don't think we should put too much effort into fixing this rather obscure problem as it is going to go away with Python 3 anyway. I added a simple workaround (untested.) Would you be fine with something like this?


New commits:

b5b7b51Do not use print function in atexit

comment:63 Changed 4 years ago by git

Commit: b5b7b518ad5ab567ac6344b4e3a0133b4362420ca4614abfd029249ce92219204f8dd5c012b99068

Branch pushed to git repo; I updated commit sha1. New commits:

a4614abMerge remote-tracking branch 'origin/develop' into 25270

comment:64 Changed 4 years ago by Julian Rüth

Status: needs_workneeds_review
Work issues: is the patchbot happy ⇒ positive reviewis the patchbot happy?

comment:65 Changed 4 years ago by Erik Bray

Status: needs_reviewpositive_review

Yes, I think this is entirely reasonable. Relying on module-level globals that may already be set to None during interpreter shutdown can always be a problem. Here instead you were getting a NameError which is a bit more strange to me, but almost certainly has some strange interplay with how from __future__ import print_function works.

Positive review from me pending patchbot results, but I think it will be fine...

comment:66 Changed 4 years ago by Volker Braun

Branch: u/saraedum/25270a4614abfd029249ce92219204f8dd5c012b99068
Resolution: fixed
Status: positive_reviewclosed

comment:67 Changed 4 years ago by Erik Bray

Commit: a4614abfd029249ce92219204f8dd5c012b99068
Milestone: sage-8.4sage-8.5

I assume?

Note: See TracTickets for help on using tickets.