#24918 closed defect (fixed)

Failing doctest in test_jupyter.rst when running patchbot

Reported by: rws Owned by:
Priority: blocker Milestone: sage-8.2
Component: interact Keywords:
Cc: Merged in:
Authors: Ralf Stephan Reviewers: Erik Bray
Report Upstream: N/A Work issues:
Branch: 80d61a0 (Commits) Commit: 80d61a074638180f1c95693208c9aff2857c9d2f
Dependencies: Stopgaps:

Description

With 8.2.beta7 all patchbots fail with:

File "src/sage/interacts/test_jupyter.rst", line 288, in sage.interacts.test_jupyter
Failed example:
    test(interacts.statistics.coin)
Expected:
    Interactive function <function coin at ...> with 2 widgets
      n: IntSlider(value=1000, description=u'Number of Tosses', max=10000, min=2, step=100)
      interval: IntRangeSlider(value=(0, 0), description=u'Plotting range (y)', max=1)
    doctest:...: UserWarning: Attempting to set identical bottom==top results
    in singular transformations; automatically expanding.
    bottom=0.0, top=0.0
Got:
    doctest:warning
      File "/home/vdelecro/sage_patchbot/src/bin/sage-runtests", line 127, in <module>
        err = DC.run()
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/doctest/control.py", line 1163, in run
        self.run_doctests()
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/doctest/control.py", line 891, in run_doctests
        self.dispatcher.dispatch()
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 1835, in dispatch
        self.parallel_dispatch()
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 1732, in parallel_dispatch
        w.start()  # This might take some time
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 2001, in start
        super(DocTestWorker, self).start()
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/multiprocessing/process.py", line 130, in start
        self._popen = Popen(self)
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/multiprocessing/forking.py", line 126, in __init__
        code = process_obj._bootstrap()
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/multiprocessing/process.py", line 267, in _bootstrap
        self.run()
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 1974, in run
        task(self.options, self.outtmpfile, msgpipe, self.result_queue)
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 2291, in __call__
        result = runner.run(test)
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 721, in run
        return self._run(test, compileflags, out)
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 537, in _run
        self.compile_and_execute(example, compiler, test.globs)
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/doctest/forker.py", line 947, in compile_and_execute
        exec(compiled, globs)
      File "<doctest sage.interacts.test_jupyter[27]>", line 1, in <module>
        test(interacts.statistics.coin)
      File "<doctest sage.interacts.test_jupyter[3]>", line 6, in test
        return f(**kwargs)
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/interacts/library.py", line 736, in coin
        show(point(c[1:], gridlines=[None, [0.5]], pointsize=1), ymin=interval[0], ymax=interval[1])
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/repl/rich_output/pretty_print.py", line 258, in show
        pretty_print(*args, **kwds)
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/repl/rich_output/pretty_print.py", line 229, in pretty_print
        dm.display_immediately(*args, **kwds)
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/repl/rich_output/display_manager.py", line 833, in display_immediately
        plain_text, rich_output = self._rich_output_formatter(obj, rich_repr_kwds)
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/repl/rich_output/display_manager.py", line 623, in _rich_output_formatter
        rich_output = self._call_rich_repr(obj, rich_repr_kwds)
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/repl/rich_output/display_manager.py", line 581, in _call_rich_repr
        return obj._rich_repr_(self, **rich_repr_kwds)
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/plot/graphics.py", line 884, in _rich_repr_
        self.save, kwds, file_ext, output_container)
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/repl/rich_output/display_manager.py", line 711, in graphics_from_save
        save_function(filename, **kwds)
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/misc/decorators.py", line 483, in wrapper
        return func(*args, **kwds)
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/plot/graphics.py", line 3153, in save
        figure = self.matplotlib(**options)
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/sage/plot/graphics.py", line 2680, in matplotlib
        subplot.set_ylim([ymin, ymax])
      File "/home/vdelecro/sage_patchbot/local/lib/python2.7/site-packages/matplotlib/axes/_base.py", line 3239, in set_ylim
        'bottom=%s, top=%s') % (bottom, top))
    :
    UserWarning: Attempting to set identical bottom==top results
    in singular transformations; automatically expanding.
    bottom=0.0, top=0.0
    Interactive function <function coin at 0x7fc26c78baa0> with 2 widgets
      n: IntSlider(value=1000, description=u'Number of Tosses', max=10000, min=2, step=100)
      interval: IntRangeSlider(value=(0, 0), description=u'Plotting range (y)', max=1)

Change History (28)

comment:1 follow-up: Changed 21 months ago by rws

The parts with "Interactive function" and "doctest" are reversed, and in "doctest" a backtrace is inserted. Race condition?

comment:2 Changed 21 months ago by rws

Can the output of warnings (presumably from matplotlib?) be silenced in these tests? They don't seem to add anything.

comment:3 Changed 21 months ago by rws

  • Branch set to u/rws/failing_doctest_in_test_jupyter_rst_when_running_patchbot

comment:4 Changed 21 months ago by rws

  • Authors set to Ralf Stephan
  • Commit set to 12a6c823cb0e834d933542b37023c0aa2d076e7b
  • Status changed from new to needs_review

Let's see if the patchbots like that more.


New commits:

12a6c8224918: fix doctest

comment:5 in reply to: ↑ 1 Changed 21 months ago by jdemeyer

Replying to rws:

in "doctest" a backtrace is inserted.

That's normal for doctests.

The reordering is mysterious though. It's especially mysterious that it happens only on the patchbots.

The cause is likely #24771.

comment:6 Changed 21 months ago by embray

I agree--the warning is from matplotlib and not really at all interesting for the purposes of these docs.

comment:7 follow-ups: Changed 21 months ago by embray

Having warnings go to sys.stderr makes sense, but it is a problem when it comes to unpredictable interleaving of stdout and stderr. I could suggest that when running the doctests all warnings just go to stdout, but really this is a general problem for any test that looked at interleaved output on stdout and stderr. I'm not really sure why it just came up in this case.

comment:8 in reply to: ↑ 7 Changed 21 months ago by jdemeyer

Replying to embray:

Having warnings go to sys.stderr makes sense, but it is a problem when it comes to unpredictable interleaving of stdout and stderr.

I agree, but that does not explain why it fails only on the patchbot.

comment:9 in reply to: ↑ 7 Changed 21 months ago by rws

Replying to embray:

Having warnings go to sys.stderr makes sense, but it is a problem when it comes to unpredictable interleaving of stdout and stderr.

In principle this is also the case with #24920. If one could just switch off stderr for those tests the linking of a system readline would not be necessary to make those tests pass.

comment:10 Changed 21 months ago by embray

The patchbot runner simply runs ./sage -t using os.system, so on its own that shouldn't make a difference.

However, I was able to make this fail consistently by running sp.Popen(['./sage', '-t', 'src/sage/interacts/test_jupyter.rst'], stdout=sp.PIPE) (where sp is the subprocess module).

So it might just be some difference, when the patchbot itself is run, in type of file stdout and/or stderr, whether or not those files are buffered, and the size of the buffer.

comment:11 Changed 21 months ago by embray

Even more simply, I can reproduce just by running ./sage -t src/sage/interacts/test_jupyter.rst > test.txt, for example.

comment:12 Changed 21 months ago by rws

The test:

    sage: test(interacts.statistics.coin)
    ...
    Interactive function <function coin at ...> with 2 widgets
      n: IntSlider(value=1000, description=u'Number of Tosses', max=10000, min=2, step=100)
      interval: IntRangeSlider(value=(0, 0), description=u'Plotting range (y)', max=1)
    ...

The test run:

Failed example:
    test(interacts.statistics.coin)
Expected:
    Interactive function <function coin at ...> with 2 widgets
      n: IntSlider(value=1000, description=u'Number of Tosses', max=10000, min=2
, step=100)
      interval: IntRangeSlider(value=(0, 0), description=u'Plotting range (y)', 
max=1)
    ...

It appears that ellipsis at the start of the output part of the doctest is ignored, is this a feature? If not immediately fixable I propose to "known bug" this doctest for now.

comment:13 Changed 21 months ago by embray

It does make more sense that the warning should come first in the output. But whether or not it actually does come first depends on I/O buffering peculiarities it seems.

comment:14 follow-up: Changed 21 months ago by jdemeyer

One simple workaround would be to flush stdout before printing the warning. That's literally a 1-line fix.

comment:15 in reply to: ↑ 14 Changed 21 months ago by rws

Replying to jdemeyer:

One simple workaround would be to flush stdout before printing the warning. That's literally a 1-line fix.

In matplotlib/axes/_base.py, so that's a matplotlib patch I guess.

comment:16 Changed 21 months ago by jdemeyer

No, I meant in the doctest framework whenever a warning is printed.

comment:17 Changed 21 months ago by jdemeyer

I mean this change:

  • src/sage/doctest/forker.py

    diff --git a/src/sage/doctest/forker.py b/src/sage/doctest/forker.py
    index 301383b..38c5cdf 100644
    a b def showwarning_with_traceback(message, category, filename, lineno, file=None, l 
    170170        :
    171171        UserWarning: bad stuff
    172172    """
     173    # Flush stdout to get predictable ordering of output and warnings
     174    sys.stdout.flush()
     175
    173176    # Get traceback to display in warning
    174177    tb = traceback.extract_stack()
    175178    tb = tb[:-1]  # Drop this stack frame for showwarning_with_traceback()

comment:18 Changed 21 months ago by git

  • Commit changed from 12a6c823cb0e834d933542b37023c0aa2d076e7b to 857cb1503792426588ca8fd623439cd85f317d96

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

857cb1524918: apply suggested workaround

comment:19 Changed 21 months ago by embray

Yes, that makes total sense. I was just experimenting with a different approach that reopens sys.stdout and sys.stderr with unbuffered files, but this should be simpler.


New commits:

857cb1524918: apply suggested workaround

comment:20 Changed 21 months ago by rws

OK, thanks.

comment:21 Changed 21 months ago by embray

Looks like this works, though in this case you can also just remove the original fix, since now the stdout does appear before the stderr as before (I'm actually not sure why that's the case--I would think the warning would be displayed first--but apparently not).

comment:22 Changed 21 months ago by jdemeyer

  • Status changed from needs_review to needs_work

comment:23 Changed 21 months ago by rws

  • Branch changed from u/rws/failing_doctest_in_test_jupyter_rst_when_running_patchbot to u/rws/24918

comment:24 Changed 21 months ago by rws

  • Commit changed from 857cb1503792426588ca8fd623439cd85f317d96 to 80d61a074638180f1c95693208c9aff2857c9d2f
  • Status changed from needs_work to needs_review

New commits:

80d61a024918: force ordered output in doctests

comment:25 Changed 21 months ago by embray

  • Status changed from needs_review to positive_review

comment:26 Changed 21 months ago by embray

  • Reviewers set to Erik Bray

comment:27 Changed 21 months ago by rws

Thanks.

comment:28 Changed 20 months ago by vbraun

  • Branch changed from u/rws/24918 to 80d61a074638180f1c95693208c9aff2857c9d2f
  • Resolution set to fixed
  • Status changed from positive_review to closed
Note: See TracTickets for help on using tickets.