Opened 9 years ago

Last modified 5 years ago

#10294 new defect

Slowness of pexpect interfaces on some machines

Reported by: SimonKing Owned by: was
Priority: major Milestone: sage-6.4
Component: interfaces Keywords: pexpect select performance Ubuntu
Cc: AlexanderDreyer, wjp, leif Merged in:
Authors: Reviewers:
Report Upstream: Reported upstream. No feedback yet. Work issues:
Branch: Commit:
Dependencies: Stopgaps:

Description

Originally reported at sage-devel:

Some machines suffer from a massive overhead in the following test.

def test(n):
    st = singular.cputime()
    ct = cputime()
    wt = walltime()
    for i in range(n):
        a = singular(i)
    print "Wall time:", walltime(wt)
    print "Total CPU:", cputime(ct)+singular.cputime(st)

On bsd.math, one gets something like

sage: test(1000)
Wall time: 0.261538028717
Total CPU: 0.331918 

On some other machines, one may get up to

sage: test(1000)
Wall time: 59.9999949932
Total CPU: 0.05 

The reports indicate that the overhead is bad on Debian and worst on Ubuntu; it seems to be independent of the CPU. So far, there is no other variety of Linux or Unix known that shows such a massive overhead.

Studying the interface code reveals that the overhead is caused by at least two calls to select.select, that are done when pexpect is waiting for the prompt:

  1. In singular._synchronize()
  2. If garbage collection occurs, it is waited for a prompt once for each variable that is to be deleted.
  3. When the actual code is sent to singular.

This is why the overhead of the Gap interface is only one third of the above: It does not use synchronization, and if a variable is to be deleted then simply it may be overwritten when creating the next Gap element. There must be ways to improve the Singular interface, so that one or two calls to select() can be avoided.

David Kirkby suggests to try and upgrade pexpect - Sage uses version 2.0, but the current pexpect is 2.3.

I suggest that the Singular-specific problems and the pexpect upgrade are dealt with on different tickets, while this ticket focuses on the general problem of slow select() calls on some systems.

The disadvantage of my suggestion is: What could we do to overcome a system-dependent performance problem? Would there be a way to work around select()? Would it help to leave pexpect and use expect instead?

I reported the problem to the pexpect developer, but there was no answer yet. Who knows, perhaps this ticket will eventually be a "wontfix", but we should at least try...

Change History (13)

comment:1 Changed 9 years ago by SimonKing

This is related with #10295 and #10296.

comment:2 Changed 9 years ago by SimonKing

I forgot to mention a hint by Willem-Jan. He wrote on sage-devel:


Could you try to download, compile and run a small test program on a problematic machine? It times how fast a pseudo-terminal responds, which might be the problem judging by a few quick tests I ran.

wget http://www.usecode.org/misc/timeptmx.c
gcc -o timeptmx timeptmx.c
strace -o timeptmx.log -f -ttt ./timeptmx
grep aaa timeptmx.log

That should output something like this:

16095 1290175675.065705 write(3, "aaa", 3) = 3
16096 1290175675.065749 <... read resumed> "aaa", 256) = 3

The difference between these two timestamps seems to determine how fast pexpect responds. In this case it's fast (1290175675.065705 to 1290175675.065749 is only 44 microseconds), but I've seen 1.8ms on other machines with newer kernels.


I've seen even worse, namely 8ms on a Debian machine and 22ms on an Ubuntu machine.

comment:4 in reply to: ↑ 3 Changed 9 years ago by SimonKing

Replying to mhansen:

This may also be relevant: ...

Cool! Thank you!

comment:5 Changed 9 years ago by AlexanderDreyer

  • Cc AlexanderDreyer added
  • Owner changed from was to AlexanderDreyer

comment:6 Changed 9 years ago by wjp

  • Cc wjp added

comment:7 Changed 9 years ago by AlexanderDreyer

  • Owner changed from AlexanderDreyer to was

(Change in owner was not intended.)

comment:8 Changed 8 years ago by leif

  • Cc leif added

comment:9 Changed 7 years ago by roed

  • Report Upstream changed from Reported upstream. Little or no feedback. to Reported upstream. No feedback yet.

comment:10 Changed 6 years ago by jdemeyer

  • Milestone changed from sage-5.11 to sage-5.12

comment:11 Changed 6 years ago by vbraun_spam

  • Milestone changed from sage-6.1 to sage-6.2

comment:12 Changed 5 years ago by vbraun_spam

  • Milestone changed from sage-6.2 to sage-6.3

comment:13 Changed 5 years ago by vbraun_spam

  • Milestone changed from sage-6.3 to sage-6.4
Note: See TracTickets for help on using tickets.