flushing stdout during doctests

174 views
Skip to first unread message

John Cremona

unread,
Feb 26, 2019, 11:52:39 AM2/26/19
to SAGE devel
I am testing a new version of the standard spkg eclib, see https://trac.sagemath.org/ticket/27360.  I am getting doctesting failures caused *only* because of changes in output buffering resulting in the tail end of the output of one command appearing at the beginning of the output of the next.  For example if you do 

sage: E = mwrank_EllipticCurve([0,0,1,-7,6])    
sage: EQ = mwrank_MordellWeil(E)  
sage: EQ.search(2)

as in src/sage/libs/eclib/interface.py near the end, then the last of those commands causes eclib (which is a C++ library) to output some progress to stdout.  In that files there are several examples of that sort, causing output to stdout as a side-effect.  In 8.7.beta5 (and all previous versions including many previous versions of eclib) all is well, but after building the new eclib version (which makes no relevant changes whatsoever) I find that half of the last line of the side-effect output is not being sent to the output stream until the next doctest is run, with the result that both test fail since the output is not what was expected.

I based my working branch on 8.7.beta5 which works fine.  I tried adding some sys.stdout.flush() commands in the code and/or the doctests but it makes no difference -- presumably eclib's stdout is not the same channel as python's.

Any suggestions other than "you must have made some change in eclib which caused this"?  Since I didn't!?

John


Frédéric Chapoton

unread,
Feb 27, 2019, 2:35:40 AM2/27/19
to sage-devel
This problem is also seen in the python3 patchbot report, as can be found here :


Frederic

Jeroen Demeyer

unread,
Feb 27, 2019, 3:56:51 AM2/27/19
to sage-...@googlegroups.com
On 2019-02-26 17:52, John Cremona wrote:
> I am testing a new version of the standard spkg eclib, see
> https://trac.sagemath.org/ticket/27360. I am getting doctesting
> failures caused *only* because of changes in output buffering resulting
> in the tail end of the output of one command appearing at the beginning
> of the output of the next.

It would be helpful if you could post the branch that you tried on Trac
such that others can reproduce this.

John Cremona

unread,
Feb 27, 2019, 3:58:56 AM2/27/19
to SAGE devel
The problem went away after I did "make distclean; make build".

Originally what I did after checking out a new branch was 
(1) put the new tarball into upstream/
(2) edit the file build/pkgs/eclib/package-version.txt 
(3) issue the magic command which updates the checksum
(4) ./sage -i eclib [causes the new eclib to be built OK]
(5) make build  [rebuilds some cython files which depend on eclib]
(6) run tests

Surely that should work, so whatever is deciding what needs doing in step (5) is possibly not getting it quite right.

John

--
You received this message because you are subscribed to the Google Groups "sage-devel" group.
To unsubscribe from this group and stop receiving emails from it, send an email to sage-devel+...@googlegroups.com.
To post to this group, send email to sage-...@googlegroups.com.
Visit this group at https://groups.google.com/group/sage-devel.
For more options, visit https://groups.google.com/d/optout.

John Cremona

unread,
Feb 27, 2019, 4:02:53 AM2/27/19
to SAGE devel
Sorry, I just saw this request after sending just now.  Since the problem went away after a rebuild I don't think that would help.

I am now working on adapting the doctests, several of which need rather trivial changes due to the different precision handling.

Jeroen Demeyer

unread,
Feb 27, 2019, 4:02:54 AM2/27/19
to sage-...@googlegroups.com
On 2019-02-27 08:35, Frédéric Chapoton wrote:
> This problem is also seen in the python3 patchbot report, as can be
> found here :
>
> https://patchbot.sagemath.org/log/0/Ubuntu/16.04/x86_64/4.4.0-141-generic/atlas/2019-02-24%2011:31:45?short

In Python 3, the situation is different because Python implements its
own buffering for I/O. In contrast, Python 2 relies on the I/O
implementation of the C library.

Jeroen Demeyer

unread,
Feb 27, 2019, 4:09:54 AM2/27/19
to sage-...@googlegroups.com
On 2019-02-27 09:58, John Cremona wrote:
> The problem went away after I did "make distclean; make build".
>
> Originally what I did after checking out a new branch was
> (1) put the new tarball into upstream/
> (2) edit the file build/pkgs/eclib/package-version.txt
> (3) issue the magic command which updates the checksum
> (4) ./sage -i eclib [causes the new eclib to be built OK]
> (5) make build [rebuilds some cython files which depend on eclib]
> (6) run tests
>
> Surely that should work, so whatever is deciding what needs doing in
> step (5) is possibly not getting it quite right.

First of all, yes that should work. Technically, you don't even need
step (4) since the build system will detect that the version changed of
eclib.

However, I would be quite surprised if build issues would affect the
buffering of the output.

Jeroen Demeyer

unread,
Feb 27, 2019, 4:16:28 AM2/27/19
to sage-...@googlegroups.com
On 2019-02-26 17:52, John Cremona wrote:
> I am testing a new version of the standard spkg eclib, see
> https://trac.sagemath.org/ticket/27360. I am getting doctesting
> failures caused *only* because of changes in output buffering resulting
> in the tail end of the output of one command appearing at the beginning
> of the output of the next.

Since this is I/O related, it might make a difference if you redirect
stdout and/or stderr to a file. For example, doing

./sage -t somefile.py 2>err.log

instead of

./sage -t somefile.py

Do you happen to have the *exact* command line that you used to run tests?

John Cremona

unread,
Feb 27, 2019, 5:06:16 AM2/27/19
to SAGE devel
I did

./sage -t src/sage/libs/eclib

from the SAGE_ROOT directory.  No redirection.

I note that the file mwrank.pyx in that directory has in a few places in the code the lines
   if verb:
        sys.stdout.flush()
        sys.stderr.flush()

which looks like dealing with the same issue (since there will have been side-effect output iff verb)

I'll be uploading a branch to review very soon.  There were a few small changes resulting from the default precision changing from 50 digits to 150 bits.  (I know that 166 bits is closer.)  There is some stupidity here, as noted in comments, since in some cases a value is computed in eclib to higher precision but is converted to a float later.  I don't think this happens anywhere that matters:  no code or doctest changes were required outside sage/libs/eclib.
Reply all
Reply to author
Forward
0 new messages