Re: performance

[hjstein@bfr.co.il (Harvey J. Stein)]

Mikael Djurfeldt <mdj@nada.kth.se> writes:

 > Sigh...
 > 
 > Andres' figures indicated that scm5d0 was 800% faster than Guile.
 > When checking it myself I found that scm5d0 was 144% faster than the
 > debugging evaluator and 43% faster than the normal with his test
 > profram.  (I used the development snapshot, but the difference between
 > that and the released 1.3 should be withing the 30% I talked about
 > previously.)  I also could see that for something more similar to a
 > real program (Aubrey's pi.scm) scm5d0 was only 13% faster.
 > 
 > Now you claim that STk is competitive with the normal Guile evaluator.
 > 
 > I checked:
 > 
 > STk 3.99.3 took 362 s to do (pi 100 5) 60 times.  Guile's normal
 > evaluator took 61 s.  This tells me that Guile is 490% faster than
 > STk.  For the debugging evaluator it took 151 s => 140% faster than
 > STk.
 > 
 > It is obviously so that people write whatever they like without
 > checking when it concerns speed of execution, so the message is:
 > 
 > Don't listen to what people say about speed!  Check for yourself.
 > 
 > My experience hitherto is that I've never encountered *any* Scheme
 > interpreter which has been faster than Guile's normal evaluator except
 > for SCM.  So it is still my belief that Guile is the second fastest
 > interpreter in the world.  I'm amazed that people are complaining
 > about performance problems.

Obviously, speed differences will vary depending on the program being
tested:


   hjstein@blinky:~$ guile
   guile> (debug-disable 'debug)
   (stack 20000 depth 20 maxdepth 1000 frames 3 indent 10 procnames cheap)
   guile> (define-macro (unsafe-time form)
     `(let* ((t1 (get-internal-run-time))
	     (r ,form)
	     (t2 (get-internal-run-time)))
	(display "Time: ")
	(display (/ (- t2 t1) internal-time-units-per-second))
	(newline)
	r))
   guile> (define (fact n) (if (< n 1) 1 (* n (fact (- n 1)))))
   guile> (unsafe-time (fact 100))
   Time: 0
   93326215443944152681699238856266700490715968264381621468592963895217599993229915608941463976156518286253697920827223758251185210916864000000000000000000000000
   guile> (unsafe-time (fact 1000))
   Time: 0.12
   <result snipped for brevity>
   guile> (unsafe-time (begin (fact 3000) 1))
   ERROR: Stack overflow
   ABORT: (stack-overflow)
   guile> (define (factstart s n) (if (< n 1) s (factstart (* s n) (- n 1))))
   guile> (unsafe-time (factstart 1 100))
   Time: 0
   93326215443944152681699238856266700490715968264381621468592963895217599993229915608941463976156518286253697920827223758251185210916864000000000000000000000000
   guile> (unsafe-time (begin (factstart 1 3000) 1))
   Time: 1.31
   1
   guile> (unsafe-time (begin (factstart 1 3000) 1))
   Time: 1.31
   1
   guile> (debug-enable 'debug)
   (stack 20000 debug depth 20 maxdepth 1000 frames 3 indent 10 procnames cheap)
   guile> (unsafe-time (begin (factstart 1 3000) 1))
   Time: 1.32
   1
   guile> (unsafe-time (begin (factstart 1 3000) 1))
   Time: 1.32
   1
   guile> 

Compared to:

   hjstein@blinky:~$ snow
   Welcome to the STk interpreter version 3.1.1 [Linux-2.X-ix86]
   Copyright © 1993-1996 Erick Gallesio - I3S - CNRS / ESSI <eg@unice.fr>
   STk> (define (fact n) (if (< n 1) 1 (* n (fact (- n 1)))))
   #[undefined]
   STk> (time (fact 100))
   ;;    Time: 0.00ms
   ;; GC time: 0.00ms
   ;;   Cells: 402
   93326215443944152681699238856266700490715968264381621468592963895217599993229915608941463976156518286253697920827223758251185210916864000000000000000000000000
   STk> (time (begin (fact 1000) 1))
   ;;    Time: 10.00ms
   ;; GC time: 0.00ms
   ;;   Cells: 3995
   1
   STk> (define (factstart s n) (if (< n 1) s (factstart (* s n) (- n 1))))
   #[undefined]
   STk> (define unsafe-time time)
   #[undefined]
   STk> (unsafe-time (factstart 1 100))
   ;;    Time: 0.00ms
   ;; GC time: 0.00ms
   ;;   Cells: 607
   STk> (unsafe-time (begin (factstart 1 3000) 1))
   ;;    Time: 180.00ms
   ;; GC time: 10.00ms
   ;;   Cells: 18006
   1
   STk> (unsafe-time (begin (factstart 1 3000) 1))
   ;;    Time: 180.00ms
   ;; GC time: 10.00ms
   ;;   Cells: 18006
   1
   STk> (unsafe-time (begin (factstart 1 3000) 1))
   ;;    Time: 170.00ms
   ;; GC time: 10.00ms
   ;;   Cells: 18006
   1
   STk> (unsafe-time (begin (factstart 1 3000) 1))
   ;;    Time: 160.00ms
   ;; GC time: 0.00ms
   ;;   Cells: 18005
   1
   STk> (unsafe-time (begin (factstart 1 3000) 1))
   ;;    Time: 160.00ms
   ;; GC time: 10.00ms
   ;;   Cells: 18005
   1
   STk> (unsafe-time (begin (factstart 1 3000) 1))
   ;;    Time: 170.00ms
   ;; GC time: 20.00ms
   ;;   Cells: 18006
   1

Compared to:

hjstein@blinky:~$ scm
SCM version 4e5, Copyright (C) 1990, 1991, 1992, 1993, 1994, 1995, 1996 Free Software Foundation.
SCM comes with ABSOLUTELY NO WARRANTY; for details type `(terms)'.
This is free software, and you are welcome to redistribute it
under certain conditions; type `(terms)' for details.
;loading /usr/lib/scm/require
;  loading /usr/lib/slib/require
;  done loading /usr/lib/slib/require.scm
;done loading /usr/lib/scm/require.scm
;loading /usr/lib/scm/Transcen.scm
;done loading /usr/lib/scm/Transcen.scm
;Evaluation took 10 mSec (0 in gc) 11693 cells work, 14876 bytes other
> (define (fact n) (if (< n 1) 1 (* n (fact (- n 1)))))
;Evaluation took 0 mSec (0 in gc) 36 cells work, 42 bytes other
#<unspecified>
> (begin (fact 3000) 1)
;Evaluation took 530 mSec (300 in gc) 15004 cells work, 5287307 bytes other
1
>  (define (factstart s n) (if (< n 1) s (factstart (* s n) (- n 1))))
;Evaluation took 0 mSec (0 in gc) 37 cells work, 45 bytes other
#<unspecified>
>  (begin (factstart 1 3000) 1)
;Evaluation took 510 mSec (230 in gc) 18016 cells work, 6092927 bytes other
1
> (begin (factstart 1 3000) 1)
;Evaluation took 510 mSec (290 in gc) 18014 cells work, 6092927 bytes other
1
> (begin (factstart 1 3000) 1)
;Evaluation took 510 mSec (280 in gc) 18014 cells work, 6092927 bytes other
1
> 

So, STk is a factor of 6.9 - 8.25 (depending on which timings you
compare) faster than guile and scm is about a factor of about 2.5
faster.

I *will* weaken my claim to be that I've observed STk being
substantially faster than guile, but it obviously depends on the
problem at hand.

BTW what's *much* worse than the above is that when I don't disable
debugging immediately on startup then the guile time is 1.61 instead
of 1.31.  Loading the code with the debugging interpreter causes it to
run slower when using the non-debuggging interpreter!

And, before this generates 30 messages about what exactly this above
test shows, I'd like to also point out the obvious - the above test is
probably more of the speed of the bignum subsystem, than the
interpreter itself.  It's probably the case that STk's bignum
subsystem is much faster than guile's.  Maybe bignums are faster, but
inexact number handling is slower?  Such analyses are more important
for those trying to improve guile than those trying to use it.

On "real" applications, I've also found STk to be faster than guile.
This time, it might be the I/O subsystem, or the regexp subsystem, or
...  But the more this occurs, the more it makes it looks like a large
part of guile is just slow.

In any case, lets get back to the issue at hand - how about turning
off debugging by default?  It makes guile look bad, it causes users to
flee, developers can turn it on for development, the fact that it
bulks up the code during reading (a guess) is probably having a bad
interaction with the GC causing *loading* with debugging turned on to
slow down code that's *run* with debugging turned off, ...

-- 
Harvey J. Stein
BFM Financial Research
hjstein@bfr.co.il