Re: [Gcl-devel] efficiency of package symbol tables

[Peter Wood]

Hi

On Thu, Mar 04, 2004 at 10:05:04PM +0100, Bruno Haible wrote:
> Hi, ...

I replied to this early (too early!) this morning and as usual wrote
rubbish.  In particular some nonsense about "only 12 buckets" which
is not true.  Hopefully, that mail has been lost :-) Anyway, I have
had time to think about this a bit more (and actually look at GCL's
pack_hash() code, and I do not believe there is a bug at all (at least
not in pack_hash()).  I am running a very old version of GCL, but I'll
bet that pack_hash() has not changed over the centuries.

I think its a simple GC issue (in GCL at least).  Here are my
adjusted GC settings and my timings for the test code that Bruno
posted:  Note that all of these adjustments might not be necessary,
and some of couls be overkill.

(proclaim '(optimize (speed 3) (safety 0) (space 0)))

(setf si::*notify-gbc* t)
(si::gbc-time 0)
(si::set-hole-size 5000)
(allocate 'symbol 40000)
(allocate 'fixnum 2000)
(allocate 'string 40000)
(allocate 'cons 40000)
(si::allocate-relocatable-pages 20000)
(si::allocate-contiguous-pages 1000)
(si::allocate-growth 'symbol 1 8000 100)
(si::allocate-growth 'array 1 8000 100)
(si::allocate-growth 'fixnum 1 8000 100)
(si::allocate-growth 'string 1 8000 100)
(si::allocate-growth 'cons 1 8000 100)

(defun random-symbol () 
  (intern (write-to-string (random 1000000000000000000) :base 36)
          *package*))
        
(defun fill-symtab (n)
  (dotimes (i n) (random-symbol)))

I compiled the file and obtained the following timings for n ==
100000.

>(time (fill-symtab 100000))
[GC for 0 RELOCATABLE-BLOCKS pages..(T=3).GC finished]
[GC for 0 RELOCATABLE-BLOCKS pages..(T=15).GC finished]
real time : 3.000 secs
run time  : 2.480 secs
NIL

>(time (fill-symtab 100000))
[GC for 0 RELOCATABLE-BLOCKS pages..(T=33).GC finished]
real time : 3.000 secs
run time  : 2.740 secs
NIL

>(time (fill-symtab 100000))
[GC for 0 CONTIGUOUS-BLOCKS pages..(T=49).GC finished]
[GC for 0 CONTIGUOUS-BLOCKS pages..(T=43).GC finished]
real time : 3.000 secs
run time  : 3.420 secs
NIL

>(time (fill-symtab 100000))
[GC for 0 RELOCATABLE-BLOCKS pages..(T=70).GC finished]
real time : 2.000 secs
run time  : 2.910 secs
NIL

>(time (fill-symtab 100000))
real time : 2.000 secs
run time  : 2.270 secs
NIL

>(time (fill-symtab 100000))
[GC for 0 RELOCATABLE-BLOCKS pages..(T=90).GC finished]
real time : 4.000 secs
run time  : 3.220 secs
NIL

>(time (fill-symtab 100000))
[GC for 0 RELOCATABLE-BLOCKS pages..(T=117).GC finished]
real time : 4.000 secs
run time  : 3.510 secs
NIL

>(time (fill-symtab 100000))
real time : 3.000 secs
run time  : 2.400 secs
NIL

>(time (fill-symtab 100000))
[GC for 0 RELOCATABLE-BLOCKS pages..(T=143).GC finished]
real time : 4.000 secs
run time  : 3.850 secs
NIL

>(time (fill-symtab 100000))
real time : 3.000 secs
run time  : 2.480 secs
NIL

>(time (fill-symtab 100000))
[GC for 0 RELOCATABLE-BLOCKS pages..(T=175).GC finished]
[GC for 0 CONTIGUOUS-BLOCKS pages..(T=167).GC finished]
[GC for 0 CONTIGUOUS-BLOCKS pages..(T=168).GC finished]
real time : 8.000 secs
run time  : 8.430 secs
NIL

>(time (fill-symtab 100000))
real time : 2.000 secs
run time  : 2.420 secs
NIL

Well the GC stuff is not too pretty!  But I think the hash access
times are ok.  The final time obtained after interning 100000 symbols
12 times looks good enough to me.  It certainly compares favourably to
the other times the test ran without a GC.

In a fresh image, further increasing the values for nrs of relocatable
and contiguous pages and decreasing the value of n in the test gives
an even clearer picture that this is not a package hash issue:

(si::allocate-relocatable-pages 30000)
(si::allocate-contiguous-pages 8000)

>(time (fill-symtab 10000))
[GC for 0 RELOCATABLE-BLOCKS pages..(T=2).GC finished]
real time : 0.000 secs
run time  : 0.250 secs
NIL

>(time (fill-symtab 10000))
real time : 1.000 secs
run time  : 0.230 secs
NIL

>(time (fill-symtab 10000))
real time : 0.000 secs
run time  : 0.210 secs
NIL

>(time (fill-symtab 10000))
real time : 0.000 secs
run time  : 0.210 secs
NIL

>(time (fill-symtab 10000))
real time : 0.000 secs
run time  : 0.220 secs
NIL

>(time (fill-symtab 10000))
real time : 0.000 secs
run time  : 0.230 secs
NIL

>(time (fill-symtab 10000))
[GC for 0 RELOCATABLE-BLOCKS pages..(T=15).GC finished]
real time : 1.000 secs
run time  : 0.450 secs
NIL

>(time (fill-symtab 10000))
real time : 0.000 secs
run time  : 0.220 secs
NIL

>(time (fill-symtab 10000))
real time : 0.000 secs
run time  : 0.220 secs
NIL

>(time (fill-symtab 10000))
real time : 0.000 secs
run time  : 0.220 secs
NIL

>(time (fill-symtab 10000))
real time : 0.000 secs
run time  : 0.230 secs
NIL

>(time (fill-symtab 10000))
real time : 1.000 secs
run time  : 0.230 secs
NIL

>(time (fill-symtab 10000))
real time : 0.000 secs
run time  : 0.230 secs
NIL

>(time (fill-symtab 10000))
real time : 0.000 secs
run time  : 0.390 secs
NIL

>(time (fill-symtab 10000))
real time : 0.000 secs
run time  : 0.230 secs
NIL

>(time (fill-symtab 10000))
[GC for 0 RELOCATABLE-BLOCKS pages..(T=34).GC finished]
real time : 1.000 secs
run time  : 0.570 secs
NIL

>(time (fill-symtab 10000))
real time : 0.000 secs
run time  : 0.230 secs
NIL

>(time (fill-symtab 10000))
real time : 0.000 secs
run time  : 0.230 secs
NIL

>(time (fill-symtab 10000))
real time : 1.000 secs
run time  : 0.230 secs
NIL

> Sam Steingold and I found a performance problem in clisp, and it appears
> that GCL has the same problem: When tens of thousands of symbols are added
> to a package, further package lookups and symbol additions become slower
> and slower. This is of course not the proper behaviour for good hash tables.
> 
> Here is the test code:
> 
> (defun random-symbol ()
>   (intern (write-to-string (random 1000000000000000000) :base 36)
>           *package*))
> (compile 'random-symbol)
> 
> (defun fill-symtab (n)
>   (dotimes (i n) (random-symbol)))
> (compile 'fill-symtab)
> 
> 
> And here are the timings with gcl-2.5.3:
> 
> 
> >(time (fill-symtab 10000))
> 
> real time : 0.090 secs
> run time  : 0.090 secs
> NIL
> 
> >(time (fill-symtab 10000))
> 
> real time : 0.180 secs
> run time  : 0.190 secs
> NIL
> 
> >(time (fill-symtab 10000))
> 
> real time : 0.240 secs
> run time  : 0.250 secs
> NIL
> 
> >(time (fill-symtab 10000))
> 
> real time : 0.260 secs
> run time  : 0.260 secs
> NIL
> 
> >(time (fill-symtab 10000))
> 
> real time : 0.330 secs
> run time  : 0.330 secs
> NIL
> 
> >(time (fill-symtab 10000))
> 
> real time : 0.350 secs
> run time  : 0.340 secs
> NIL
> 
> >(time (fill-symtab 10000))
> 
> real time : 0.420 secs
> run time  : 0.410 secs
> NIL
> 
> >(time (fill-symtab 10000))
> 
> real time : 0.480 secs
> run time  : 0.470 secs
> NIL
> 
> >(time (fill-symtab 10000))
> 
> real time : 0.460 secs
> run time  : 0.460 secs
> NIL
> 
> >(time (fill-symtab 10000))
> 
> real time : 0.470 secs
> run time  : 0.470 secs
> NIL
> 
> >(time (fill-symtab 100000))
> 
> real time : 8.040 secs
> run time  : 7.460 secs
> NIL
> 
> >(time (fill-symtab 100000))
> 
> real time : 11.950 secs
> run time  : 11.890 secs
> NIL
> 
> >(time (fill-symtab 100000))
> 
> real time : 15.900 secs
> run time  : 15.610 secs
> NIL
> 
> >(time (fill-symtab 100000))
> 
> real time : 19.980 secs
> run time  : 19.880 secs
> NIL
> 
> >(time (fill-symtab 100000))
> 
> real time : 24.380 secs
> run time  : 24.160 secs
> NIL
> 
> 
> What helped us in order to understand the problem, was to look at the
> internal distribution, how many symbols in each bucket of the hash table
> on average...
> 
> Regards,
> 
> Bruno
> 
> 
> PS: Btw, INTERN gives a wrong error message:
> 
> (intern "FOO" "CL-USER")
> 
> Error: "CL-USER" is not of type (OR SYMBOL STRING ...).
> Fast links are on: do (si::use-fast-links nil) for debugging
> Error signalled by INTERN.
> Broken at INTERN.  Type :H for Help.
> 
> What it means to say is that the package CL-USER does not exist...

There are lots of problems with GCL's error system.

Regards,
Peter