Failures in gp pexpect interface with specific length of $DOT_SAGE using a "screen" terminal

[Jeroen Demeyer]

On Gentoo Linux x86_64 and on sage.math running sage-4.8.alpha6 + #11073 (but without #12263):

Use a "screen" terminal.

When $DOT_SAGE (and therefore, $HOME) contains a specific number of characters in relation to the number of columns on the pseudo-terminal ($COLUMNS), failures happen. I believe this is due to temporary filenames word-wrapping in the pseudo-terminal (pty). The pty seems to inherit properties of the actual terminal, that's why there are failures with screen but not with xterm.

For example, on a 138-column terminal:

( export HOME=/mnt/usb1/scratch/jdemeyer/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx; mkdir -p $HOME; ./sage -t devel/sage/sage/schemes )
[...]
sage -t  "devel/sage/sage/schemes/elliptic_curves/ell_rational_field.py"
  ***   Warning: new stack size = 1003360 (0.957 Mbytes).
  ***   Warning: new stack size = 1003360 (0.957 Mbytes).
**********************************************************************
File "/usr/local/src/sage-4.8.alpha4/devel/sage/sage/schemes/elliptic_curves/ell_rational_field.py", line 526:
    sage: E.conductor(algorithm="gp")
Exception raised:
    Traceback (most recent call last):
      File "/usr/local/src/sage-4.8.alpha4/local/bin/ncadoctest.py", line 1231, in run_one_test
        self.run_one_example(test, example, filename, compileflags)
      File "/usr/local/src/sage-4.8.alpha4/local/bin/sagedoctest.py", line 38, in run_one_example
        OrigDocTestRunner.run_one_example(self, test, example, filename, compileflags)
      File "/usr/local/src/sage-4.8.alpha4/local/bin/ncadoctest.py", line 1172, in run_one_example
        compileflags, 1) in test.globs
      File "<doctest __main__.example_12[5]>", line 1, in <module>
        E.conductor(algorithm="gp")###line 526:
    sage: E.conductor(algorithm="gp")
      File "/usr/local/src/sage-4.8.alpha4/local/lib/python/site-packages/sage/schemes/elliptic_curves/ell_rational_field.py", line 552, in conductor
        self.__conductor_gp = Integer(gp.eval('ellglobalred(ellinit(%s,0))[1]'%list(self.a_invariants())))
      File "integer.pyx", line 681, in sage.rings.integer.Integer.__init__ (sage/rings/integer.c:6786)
    TypeError: unable to convert x (=read("/tmp/123456789_123456789_123456789_123456789_123456789_123456789_123456789_123456789/.sage/temp/arcanis/5630//interface//tmp5647") ) to an integer
**********************************************************************
File "/usr/local/src/sage-4.8.alpha4/devel/sage/sage/schemes/elliptic_curves/ell_rational_field.py", line 1430:
    sage: E.simon_two_descent()
Exception raised:
    Traceback (most recent call last):
      File "/usr/local/src/sage-4.8.alpha4/local/bin/ncadoctest.py", line 1231, in run_one_test
        self.run_one_example(test, example, filename, compileflags)
      File "/usr/local/src/sage-4.8.alpha4/local/bin/sagedoctest.py", line 38, in run_one_example
        OrigDocTestRunner.run_one_example(self, test, example, filename, compileflags)
      File "/usr/local/src/sage-4.8.alpha4/local/bin/ncadoctest.py", line 1172, in run_one_example
        compileflags, 1) in test.globs
      File "<doctest __main__.example_28[4]>", line 1, in <module>
        E.simon_two_descent()###line 1430:
    sage: E.simon_two_descent()
      File "/usr/local/src/sage-4.8.alpha4/local/lib/python/site-packages/sage/schemes/elliptic_curves/ell_rational_field.py", line 1493, in simon_two_descent
        maxprob=maxprob, limbigprime=limbigprime)
      File "/usr/local/src/sage-4.8.alpha4/local/lib/python/site-packages/sage/schemes/elliptic_curves/gp_simon.py", line 117, in simon_two_descent
        ans = sage_eval(v, {'Mod': _gp_mod, 'y': K.gen(0)})
      File "/usr/local/src/sage-4.8.alpha4/local/lib/python/site-packages/sage/misc/sage_eval.py", line 199, in sage_eval
        return eval(source, sage.all.__dict__, locals)
      File "<string>", line 0

        ^
     SyntaxError: unexpected EOF while parsing
**********************************************************************
[...]
The following tests failed:

        sage -t  devel/sage/sage/schemes/elliptic_curves/lseries_ell.py # 1 doctests failed
        sage -t  devel/sage/sage/schemes/elliptic_curves/gp_simon.py # 3 doctests failed
        sage -t  devel/sage/sage/schemes/elliptic_curves/BSD.py # 3 doctests failed
        sage -t  devel/sage/sage/schemes/elliptic_curves/sha_tate.py # 4 doctests failed
        sage -t  devel/sage/sage/schemes/elliptic_curves/ell_rational_field.py # 14 doctests failed
        sage -t  devel/sage/sage/schemes/elliptic_curves/ell_number_field.py # 11 doctests failed

---

How to reproduce this more artificially: apply 12221_debug.patch​. This will send all gp pexpect commands less than 200 characters directly to gp, without using a temporary file. The problem is the filename length of the temporary files used in the read() command. This depends on $DOT_SAGE, on the hostname, on process IDs.

Download test12221.sage​ and run (from within a "screen" session). This will execute a read() command with increasing filename lengths:

$ ./sage test12221.sage

I see

TERM = screen
18 char filename: ok
19 char filename: ok
20 char filename: ok
[...]
68 char filename: ok
69 char filename: ok
70 char filename: fail
[...]

apply 12221_pexpect_unset_TERM.patch​ and the spkg ​http://boxen.math.washington.edu/home/jdemeyer/spkg/pexpect-2.0.p5.spkg

[John Palmieri]

I can't reproduce this, either on sage.math or an OS X box. What platform were you using?

[Jeroen Demeyer]

It might really be caused by #11704 then. Need to do some more tests.

[John Palmieri]

I should clarify: I couldn't reproduce this, either before applying the patch from #11704 or after.

[Jeroen Demeyer]

It might really be caused by #11704 + #11073 then. Need to do some more tests.

[John Palmieri]

Replying to jdemeyer:

It might really be caused by #11704 + #11073 then. Need to do some more tests.

That combination doesn't cause me problems on sage.math: I have a copy of sage in /scratch/palmieri/11073/sage-4.8.a4-11073 which has the patches from #11073 and its dependencies, including #11704. Tests pass when I use the command in the ticket description. (I produced this version of Sage with the file ​http://sage.math.washington.edu/home/palmieri/misc/11073/sage-4.8.a4-11073.tar.)

[Jeroen Demeyer]

Now I also have problems reproducing it. It must be some strange interaction between several tickets.

[Jeroen Demeyer]

Maybe it's a race condition of some sort being triggered by #11704?

[Jeroen Demeyer]

I can't seem to reproduce this anymore...

[Jeroen Demeyer]

Reproducing it again sometimes when merging #11073... must be some race condition, which makes it an even more annoying bug.

[Jeroen Demeyer]

These errors happen much less frequently (but they still do happen) with python-2.7. At least that's my feeling.

[Jeroen Demeyer]

Important data point: the failures seem to happen only (or at least mostly) during the first test run. Running "make ptest" from a fresh install causes a lot of failures. Running "make ptest" a second time gives no (or much less) failures.

[Jeroen Demeyer]

This observation about the "first run" could be because of a cold disk cache causing some race condition.

[Jeroen Demeyer]

Very experimental fix seems to work on first sight, certainly needs more testing.

[Volker Braun]

For the record, I still can't reproduce it on Fedora 16:

[vbraun@volker-laptop-two hg]$ hg qapplied
12221_debug.patch
[vbraun@volker-laptop-two hg]$ export TERM=screen
[vbraun@volker-laptop-two hg]$ sage /tmp/test12221.sage 
TERM = screen
18 char filename: ok
19 char filename: ok
[...
117 char filename: ok

[wjp]

I haven't looked at this at all, but it's probably safer to set TERM to `dumb' than unsetting it. (As also evidenced by the termcap crash in #12282)

[Jeroen Demeyer]

Volker: you need to actually use "screen", not just set TERM=screen.

And then the obvious: is your sage executable the same as ./sage and did you run ./sage -b?

[Jeroen Demeyer]

Replying to wjp:

I haven't looked at this at all, but it's probably safer to set TERM to `dumb' than unsetting it. (As also evidenced by the termcap crash in #12282)

I already tried this and unfortunately the error still remains with TERM=dumb.

[Volker Braun]

I tried it under screen as well without problems. I also tried running the loop longer and this works until I hit the 255 byte filename limit in ext4:

269 char filename: ok
270 char filename: ok
Traceback (most recent call last):
  File "/tmp/test12221.py", line 11, in <module>
    f = open(gpfilename, "w")
IOError: [Errno 36] File name too long: '/tmp/tmppzCAbE/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx.gp'

[wjp]

I can reproduce the failing test12221.sage at home in a screen session, but it goes away with TERM=dumb.

On sage.math the test doesn't fail for me, but I do get a lot of escape sequences (1b 4d, followed by a lot of 1b 5b 43, followed by a 1b 5b 4b) when the length hits 70.

[wjp]

With some terminal capabilities, gp is using escape sequences to "redraw" the current line once you send a newline after exactly the right (or wrong) input line length. This redrawing of the current line includes the prompt characters, and that triggers pexpect to output the next command prematurely, getting things out of sync.

[Jeroen Demeyer]

Diff for the pexpect spkg, for review only

[Georg S. Weber]

Well, I'm not too fond of mixing up the change of "eval_using_file_cutoff" value from 50 to 1024 (in "12221_pexpect_unset_TERM.patch") on the one hand, and the safer handling of the "TERM" envorinment variable on the other hand --- these seem orthogonal action items to me, being worth independent tickets.

However, none of these changes makes the situation worse than before, and the cleaning up of the pexpect spkg alone is worth to have this getting in the main tree as soon as possible.

Cheers, Georg

[Jeroen Demeyer]

Replying to GeorgSWeber:

Well, I'm not too fond of mixing up the change of "eval_using_file_cutoff" value from 50 to 1024 (in "12221_pexpect_unset_TERM.patch") on the one hand, and the safer handling of the "TERM" envorinment variable on the other hand --- these seem orthogonal action items to me, being worth independent tickets.

Fair enough, see #12330.

[Jeroen Demeyer]

Georg, would you mind reviewing #12330 then?