On Sun, Aug 23, 2009 at 6:37 PM, Nils Bruin<nbr...@sfu.ca> wrote:
>
> On Aug 23, 1:58 pm, William Stein <wst...@gmail.com> wrote:
>> To whet our appetite though, might you do some benchmarks that compare
>> the speed of adding 2+2 via the library and via pexpect?
>
> OK, here's a little experiment. I thought adding 2 and 2 would be too
> hard for now, so I stuck with 1+2. Good news is that all routines
> arrived at the correct answer. I did count the conversions back and
> forth every time as well, so times are not so very low. The
> conversions are completely string based, so I think performance can be
> quite a bit better still. Anyway, results:
>
> ecl/library (+ 2 2): 27.6 µs per loop
> maxima/library(+ 2 2): 134 µs per loop
> maxima/pexpect(+ 2 2): 4.97 ms per loop
> python/strings(2+2): 14 µs per loop
>
> So yes, library access does work a little better than pexpect.
>
> code used:
>
> sage: from sage.libs.ecl import *
> sage: init_ecl()
> sage: ecl_eval("(require 'asdf)")
> ;;; Loading #P"/home/wstein/build/sage-4.1.1/local/lib/ecl-9.4.1/
> asdf.fas"
> ;;; Loading #P"/home/wstein/build/sage-4.1.1/local/lib/ecl-9.4.1/
> cmp.fas"
> ;;; Loading #P"/home/wstein/build/sage-4.1.1/local/lib/ecl-9.4.1/
> sysfun.lsp"
> <ECL: ("ASDF" "CMP") >
> sage: ecl_eval('(load "%s")'%(SAGE_ROOT+"/local/lib/maxima/
> maxima.fasb"))
> ;;; Loading "/scratch/nbruin/sage-4.1.1-ecl-x86_64-Linux/local/lib/
> maxima/maxima.fasb"
> <ECL: #P"/scratch/nbruin/sage-4.1.1-ecl-x86_64-Linux/local/lib/maxima/
> maxima.fasb" >
> sage: ecl_eval('(in-package :maxima)')
> <ECL: #<"MAXIMA" package> >
> sage:
> sage: def ecladd(a,b):
> ....: return eval(str(ecl_eval('(+ %s %s)'%(a,b))));
> ....:
> sage: def libadd(a,b):
> ....: return eval(str(ecl_eval('(MEVAL #$ %s + %s$)'%(a,b))))
> ....:
> sage: def maxadd(a,b):
> ....: return (maxima(a)+maxima(b)).sage()
> ....:
> sage: def pythadd(a,b):
> ....: return eval("%s + %s"%(a,b))
> ....:
> sage: timeit("ecladd(1,2)")
> 625 loops, best of 3: 27.6 µs per loop
> sage: timeit("libadd(1,2)")
> 625 loops, best of 3: 134 µs per loop
First, shouldn't you compare with:
sage: timeit("str(maxima.eval('1+2'))")
5 loops, best of 3: 584 µs per loop
rather than what you put above. The above is much more comparable.
If the speedup by switching to the C library is really going to only
be 584/134.0 = 4.358..., then I'm worried it isn't worth it. Is the
Maxima parser just really really slow?
In fact, I am mildly surprised that the above two timings between ecl
and maxima are so different. I wonder why it is an order of magnitude
faster to compute "(+ 1 2)" than to compute "(MEVAL #$ 1 + 2$)".
Perhaps in the second case the Maxima parser has to parse "1+2"?
Here are some other relevant timings (the below is on sage.math.washington.edu):
sage: timeit("str(pari('1+2'))")
625 loops, best of 3: 5.12 µs per loop
sage: timeit("pari('1+2')")
625 loops, best of 3: 3.33 µs per loop
sage: timeit("str(gap.eval('1+2'))")
625 loops, best of 3: 223 µs per loop
sage: timeit("str(gp.eval('1+2'))")
625 loops, best of 3: 95.7 µs per loop
I just noticed that maxima.eval gets dramatically slower every time it
is called even on this simple benchmark:
sage: timeit("str(maxima.eval('1+2'))")
5 loops, best of 3: 758 µs per loop
sage: timeit("str(maxima.eval('1+2'))")
625 loops, best of 3: 1.22 ms per loop
sage: timeit("str(maxima.eval('1+2'))")
125 loops, best of 3: 2.98 ms per loop
sage: timeit("str(maxima.eval('1+2'))")
125 loops, best of 3: 3.97 ms per loop
I can think of absolutely no logical reason for this. (Yes, I know
similar things in more complicated situations have been pointed out
before.) This is not a generic pexpect interface issue, since it does
not happen with other interfaces, e.g., the GP/pari interface:
sage: timeit("str(gp.eval('1+2'))")
625 loops, best of 3: 169 µs per loop
sage: timeit("str(gp.eval('1+2'))")
625 loops, best of 3: 170 µs per loop
sage: timeit("str(gp.eval('1+2'))")
625 loops, best of 3: 170 µs per loop
sage: timeit("str(gp.eval('1+2'))")
625 loops, best of 3: 169 µs per loop
or the GAP interface:
sage: timeit("str(gap.eval('1+2'))")
625 loops, best of 3: 220 µs per loop
sage: timeit("str(gap.eval('1+2'))")
625 loops, best of 3: 217 µs per loop
sage: timeit("str(gap.eval('1+2'))")
625 loops, best of 3: 215 µs per loop
sage: timeit("str(gap.eval('1+2'))")
625 loops, best of 3: 218 µs per loop
So there is something *seriously* foo-bared about Sage's
communications with Maxima that doesn't appear with the other pexpect
interfaces. It's also possible that Maxima+ecl parser just degrades
over time. We had the same problem in Sage-3.4 before switching to
ECL, by the way, except then the time started out a lot slower than
with ECL, but got badly just as quickly:
wst...@sage:/disk/scratch/mabshoff-sage-releases/sage-3.4$ ./sage
----------------------------------------------------------------------
| Sage Version 3.4, Release Date: 2009-03-11 |
| Type notebook() for the GUI, and license() for information. |
----------------------------------------------------------------------
sage: timeit("str(maxima.eval('1+2'))")
5 loops, best of 3: 2.06 ms per loop
sage: timeit("str(maxima.eval('1+2'))")
125 loops, best of 3: 2.32 ms per loop
sage: timeit("str(maxima.eval('1+2'))")
125 loops, best of 3: 2.64 ms per loop
sage: timeit("str(maxima.eval('1+2'))")
125 loops, best of 3: 2.88 ms per loop
sage: timeit("str(maxima.eval('1+2'))")
125 loops, best of 3: 3.09 ms per loop
sage: timeit("str(maxima.eval('1+2'))")
125 loops, best of 3: 3.23 ms per loop
sage: timeit("str(maxima.eval('1+2'))")
125 loops, best of 3: 3.43 ms per loop
Robert Dodier -- do you have any crazy ideas why Maxima might get
slower to do the same thing over time? Is it caching all output
somewhere? What other caching might be going on?
To see what's happening I logged all the IO between Maxima and Sage
while it gets slower as follows:
wst...@sage:~$ sage
----------------------------------------------------------------------
| Sage Version 4.1.1, Release Date: 2009-08-14 |
| Type notebook() for the GUI, and license() for information. |
----------------------------------------------------------------------
sage: m = Maxima(logfile="/home/wstein/tmp/maxima.log")
sage: timeit("m.eval('1+2')")
5 loops, best of 3: 681 µs per loop
sage: timeit("m.eval('1+2')")
625 loops, best of 3: 1.22 ms per loop
sage: timeit("m.eval('1+2')")
125 loops, best of 3: 3.01 ms per loop
The logfile is here:
http://wstein.org/home/wstein/tmp/maxima.log
Since the synchronization may be overwhelming (or responsible), I
built another version of Sage with it disabled. The results:
sage: m = Maxima(logfile="/home/wstein/tmp/maxima-nosync.log")
sage: timeit("m.eval('1+2')")
5 loops, best of 3: 253 µs per loop
sage: timeit("m.eval('1+2')")
625 loops, best of 3: 312 µs per loop
sage: timeit("m.eval('1+2')")
625 loops, best of 3: 475 µs per loop
sage: timeit("m.eval('1+2')")
625 loops, best of 3: 658 µs per loop
sage: timeit("m.eval('1+2')")
625 loops, best of 3: 1.03 ms per loop
and the output file:
http://wstein.org/home/wstein/tmp/maxima-nosync.log
which is just lots of:
"(%i566) 1+2;
<sage-display>
(%o566) 3"
It's really disturbing that Maxima systematically slows down like
this. Again, none of the other pexpect interfaces have this problem,
at least not Mathematica, Magma, GAP, GP/PARI, MATLAB, etc. The
implementations of the different interfaces are nearly identical, so I
don't know why Maxima is messed up like this.
Nils -- can you test via the C library and see if you notice any
similar slowdown???? That could tell us something.
By the way, note the initial time of "253 µs per loop". With work,
e.g., some slight change to Maxima itself to embed some control codes
in output, one could get rid of the synchronization function. Then
Sage <--> Maxima communication would be that fast over pexpect. Is it
really the case that using the C library only speeds stuff up by a
factor of 2 for basic operations? Wow.
> sage: timeit("maxadd(1,2)")
> 5 loops, best of 3: 4.97 ms per loop
4970/134.0 = 37...
> sage: timeit("pythadd(1,2)")
> 625 loops, best of 3: 14 µs per loop
Here's something very surprising to me that has essentially nothing to
do with this discussion.
On sage.math (Linux) I get the same timing as you:
def pythadd(a,b):
sage: def pythadd(a,b):
....: return eval("%s + %s"%(a,b))
....:
sage: timeit("pythadd(1,2)")
625 loops, best of 3: 14.5 µs per loop
In shocking contrast, on OS X (on my laptop or desktop), I get vastly
worse timings:
sage: timeit("pythadd(1,2)")
625 loops, best of 3: 65.7 µs per loop
sage: timeit("eval('2+2')")
625 loops, best of 3: 57.9 µs per loop
So calling Python's eval on OS X is about 4 times slower than in Linux
on similar hardware. I didn't know that.
-- William
--
William Stein
Associate Professor of Mathematics
University of Washington
http://wstein.org
--~--~---------~--~----~------------~-------~--~----~
To post to this group, send an email to sage-devel@googlegroups.com
To unsubscribe from this group, send an email to
sage-devel-unsubscr...@googlegroups.com
For more options, visit this group at http://groups.google.com/group/sage-devel
URLs: http://www.sagemath.org
-~----------~----~----~----~------~----~------~--~---
