This is the mail archive of the guile@cygnus.com mailing list for the Guile project.


Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]

Bad news from the module/environment front



After the new environment and module implementation has been finished
I've made a few benchmarks to compare the speed of the modified
evaluator and the new module system against the old one and against
Aubrey Jaffers SCM.  The test machine was a I486, 16MB RAM running
Linux 2.0.34.


1.  guile startup time compared with perl 
-----------------------------------------

$ time /usr/bin/perl -e "print 1 + 2"                      
30.03user 0.04system 0:00.07elapsed 89%CPU (0avgtext+0avgdata 0maxresident)k
0inputs+0outputs (176major+23minor)pagefaults 0swaps

$ time ./guile -c "(display (+ 1 2))"
30.07user 0.03system 0:00.09elapsed 102%CPU (0avgtext+0avgdata 0maxresident)k
0inputs+0outputs (89major+85minor)pagefaults 0swaps

The start time could be further reduced by turning most of the module
initialisation code into a (static or dynamic linked) c module:
For example:
   scm_init_numbers (scm_root_environment);
->
  scm_make_subr("ice-9/numbers", scm_tc7_subr_1, scm_init_numbers, 
                                                   scm_c_module_registry);



2.  loading the module system and starting a repl compared with the old
    module system
-----------------------------------------------------------------------

$ time ./guile </dev/null
ice-9/guile> 0.47user 0.02system 0:00.49elapsed 98%CPU (0avgtext+0avgdata 0maxresident)k
0inputs+0outputs (92major+104minor)pagefaults 0swaps

$ time ./guile </dev/null
guile> 3.25user 0.10system 0:03.86elapsed 86%CPU (0avgtext+0avgdata 0maxresident)k
0inputs+0outputs (128major+252minor)pagefaults 0swaps

Can be further reduced by compiling the module (ice-9 guile) which
contains the module and repl code.


3. loading and evaluating the file format.scm (which is part of the
   guile distribution) three times with debugging disabled 


   new module system                    old module system
   ----------------------------------------------------------------
1    500  msec  (80 msec in gc)         940  msec  (190 msec in gc)        
gc   90   msec                          220  msec 
2    560  msec  (90 msec in gc)         990  msec  (240 msec in gc) 
gc   180  msec                          250  msec 
3    430  msec  (0 msec in gc)          750  msec  (0 msec in gc) 
gc   180  msec                          230  msec 
     ---------                          ---------
     1940 msec                          3380 msec


       SCM
      ------------------------
1    470 mSec (0 in gc) 
gc    60 mSec 
2    420 mSec (0 in gc) 
gc    50 mSec 
3    430 mSec (0 in gc) 
gc    50 mSec 
     --------
     1480 msec



4. Test of the evaluator.  All debugging options switched off, scmlit,
   guile-old and guile-new where compiled without optimizations and
   with stack checking and "cautious" enabled

----------------------------------------------------------------------
(let ((circular-list ((lambda (p)
			(set-cdr! (letrec ((loop (lambda (p)
						   (if (null? (cdr p))
						       p
						       (loop (cdr p))))))
				    (loop p))
				  p)
			p)
		      (list "-" "-" "*"))))  
  (letrec ((loop (lambda (i)
		   (letrec ((loop (lambda (i)
				    (if (< i 10000)
					(begin
					  (set! circular-list (cdr circular-list))
					  (loop (+ i 1)))))))
		     (loop 0))
		   (if (equal? (car circular-list) "*")
		       (display i)
		       (display (car circular-list)))
;		   (force-output)
		   (if (> i 50) 
		       #t
		       (loop (+ i 1))))))
    (loop 0)))

----------------------------------------------------------------------


SCM                     old guile evaluator         new environment-evaluator

14100 (10 in gc)        21520 (3430 msec in gc)      32110 (13840 msec in gc)
14040 (20 in gc)        21620 (3470 msec in gc)      31910 (13820 msec in gc) 
14790 (40 in gc)        20960 (3640 msec in gc)      32070 (13940 msec in gc) 
14030 (20 in gc)        21100 (3480 msec in gc)      33220 (13960 msec in gc) 

Why is guile so slow?   Take a look at the following code:

    case (127 & SCM_IM_LETREC):
      x = SCM_CDR (x);
      env = EXTEND_ENV (SCM_CAR (x), scm_undefineds, env);
      x = SCM_CDR (x);
      proc = SCM_CAR (x);

where EXTEND_ENV cons'es a new environment:  
#define EXTEND_ENV scm_acons

The new evaluator is even worse:

SCM 
scm_extend_env (k, v, env)
{
  SCM z;
  SCM_NEWCELL (z);
  SCM_SETCAR (z, SCM_CAR (env));
  SCM_SETCDR (z, scm_acons (k, v, SCM_CDR (env)));

  return z;
}


Aubrey Jaffer avoids the C stack and uses a software stack where he
pushes the environment smobs (yes, SCM has first class environments,
too!).


------------------------------
Profile guile-new:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total           
 time   seconds   seconds    calls  ms/call  ms/call  name    
 32.81     14.54    14.54      804    18.08    22.55  scm_ceval
 30.33     27.98    13.44                             mcount
 12.66     33.59     5.61      595     9.43     9.43  scm_gc_sweep  
  9.21     37.67     4.08   186607     0.02     0.02  scm_gc_mark   
  5.51     40.11     2.44 11390190     0.00     0.00  scm_ilookup
  1.83     40.92     0.81  2283533     0.00     0.00  scm_acons     << garbage
  1.67     41.66     0.74  2279642     0.00     0.00  scm_extend_env < 
  1.31     42.24     0.58  2277473     0.00     0.00  scm_sum
  1.29     42.81     0.57  2277422     0.00     0.00  scm_less_p

------------------------------
Profile scmlit:
Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total           
 time   seconds   seconds    calls  ms/call  ms/call  name    
 42.01     18.92    18.92      148   127.84   184.39  ceval_1
 39.32     36.63    17.71                             mcount
 10.77     41.48     4.85 19438330     0.00     0.00  ilookup
  2.75     42.72     1.24  3888433     0.00     0.00  scm_extend_env
  1.75     43.51     0.79  3888002     0.00     0.00  scm_env_cons
  1.73     44.29     0.78  3887571     0.00     0.00  sum
  1.24     44.85     0.56  3887574     0.00     0.00  lessp
  0.11     44.90     0.05    11672     0.00     0.01  egc_copy_locations



His implementation uses other tricks like storing the number of
arguments into the closure, late memoization (to avoid unmemoization
which is quite expensive if you use the unmemoization protocoll) and it
fixes lots of bugs, for example (let ((a 12) (a 13)) ..) will be
rejected.

In other words:  Guile needs a new evaluator.  If you do not object against 
it, I will port his evaluator to guile.



Jost

Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]