gmane.lisp.openmcl.devel

Boris Smilga | 17 Aug 11:14

unstable computing times with transient classes

Hello.

I would like to ask a question concerning the inner workings of CCL, which was prompted by the following events.

I was recently experimenting with transient object classes, i.e. classes which are created dynamically
and exist only as long as they have instances. (This has some affinity with how prototype-based object
systems work.) One evident approach here is to create anonymous classes using (MAKE-INSTANCE
'STANDARD-CLASS) and operate on them using MOP capabilities. What I found out, however, was that this
approach has serious performance issues.

To abstract away unnecessary details, I conducted the following experiment:

1. Generate a grove, G, which is a list of conses (KEY . VALUE) where KEYs are symbols and VALUEs are either
strings or nested groves. A good size of groves for our purposes would be in the thousands of nodes.

2a. For G (and, recursively, for each of its subgroves), create C: an anonymous STANDARD-CLASS whose
DIRECT-SLOTS are named after G's KEYs and which is a subclass of STANDARD-OBJECT.

2b. Do (REMOVE-DIRECT-SUBCLASS (FIND-CLASS 'STANDARD-OBJECT) C), so that DIRECT-SUBCLASSES of
STANDARD-OBJECT do not bloat.

2c. Create an instance of C and set its slots to the VALUEs consed on G's respective KEYs.

3. Repeat steps 2a-2c several times (for the same G), measuring the runtime.

The Lisp code for the experiment and the transcript are attached herewith. To summarize, the runtimes were
extremely unstable, rising from 1½ sec. on the 1st iteration to 49 sec. on the 16th, then quickly dropping
to 7 sec. and rising again, and so on. (I have run the test in Darwin console mode to exclude that other
software appropriates processing cycles; and it doesn't look like the time was being spent on GC.)

(Continue reading)

headers

Gary Byers | 17 Aug 15:46

Re: unstable computing times with transient classes

Naturally, when I ran your example on a machine that I could do profiling
on, I didn't see quite the variance between runs as you saw (or even as
much as I'd seen on another machine.)  I did see some (and was able
to get some profiling output), which seems to explain what's going on.
These numbers were obtained on a fairly fast x86-64 Linux box.

;;; Round 0 ;;;
(GROVE-TO-ANONYMOUS-INSTANCE GROVE) took 267,797 microseconds (0.267797 seconds) to run
                     with 4 available CPU cores.
During that period, 256,961 microseconds (0.256961 seconds) were spent in user mode
                     7,999 microseconds (0.007999 seconds) were spent in system mode
36,605 microseconds (0.036605 seconds) was spent in GC.
  11,672,272 bytes of memory allocated.
  2,213 minor page faults, 0 major page faults, 0 swaps.

and the associated profiling info, showing only those functions that
accounted for 1% or more of the total time:

2051     36.6577  <Compiled-function.FIND-GF-DISPATCH-TABLE-INDEX.0x300040165FFF>
303       5.4155  <Compiled-function.%%NTH-ARG-DCODE.0x300040161D1F>
132       2.3592  <Compiled-function.%%ONE-ARG-DCODE.0x300040162DBF>
116       2.0733  <Compiled-function.%MAYBE-STD-SLOT-VALUE-USING-CLASS.0x3000401AC55F>
112       2.0018  <Compiled-function.FAST-MOD.0x30004000ED8F>
96        1.7158  <Compiled-function.SYMBOL-NAME.0x3000400AAC0F>
74        1.3226  <METHOD-FUNCTION.(SETF.SLOT-VALUE-USING-CLASS).(T.STANDARD-CLASS.T.STANDARD-EFFECTIVE-SLOT-DEFINITION)>
72        1.2869  <Compiled-function.SLOT-ID-VALUE.0x3000401A2B3F>
61        1.0903  <Compiled-function.EQ-HASH-FIND.0x3000400600EF>
56        1.0009  <Compiled-function.GET-PROPERTIES.0x30004010CB0F>

The total time on this first round is pretty good (relative to later

(Continue reading)