Thanks, Chris, for reposting in ECJ-INTEREST for everyone to see.

ECJ's biggest performance hindrance is indeed its breeding procedure,  
mostly because we allocate lots of GPNodes and GPNode[] arrays.   
Though I'm surprised at your results, because I list below what I get  
with java -Xprof ec.Evolve -file noerc.params

Note that 38% of the time is spent in GC; but allocation isn't that  
bad at all, at least with Xprof.  new array millicode is only 1.2%   
The big kahuna in allocation is clone(), which clocks in at 21.7% (up  
from 11.4% in Java 1.3.1).  This *should* basically boil down to a  
pointer increment and a memcpy.  (As opposed to new object(), which  
is a pointer increment and a bzero).  What I think is happening is  
that the cost of other elements are being optimized out in successive  
Java versions, so allocation is becoming more costly relative to them.

But profilers are notorious for giving misleading info, and I more  
than believe that new array allocation is expensive.  Nice to see  
that the aggressive heap option

That being said, this _is_ the worst-case scenario for ECJ: symbolic  
regression combines a complex breeding procedure with a fast  
evaluation.  We tend to use ECJ on much longer evaluations than  
this.  But I'm always interested in how we might be able to speed  
ECJ's breeding up in the code.  Ideas?

One I have is to eliminate protoCloneSimple and move everything to  
just protoClone.  But that's probably not going to do anything much  
because one or the other is likely optimized out anyway.

Sean


Flat profile of 28.16 secs (1446 total ticks): main

   Interpreted + native   Method
   1.8%     0  +    26    java.lang.ClassLoader.findBootstrapClass
   1.7%     0  +    24    java.lang.ClassLoader.defineClass0
   0.7%     0  +    10    java.lang.Class.forName0
   0.6%     0  +     8    java.util.zip.ZipFile.open
   0.5%     0  +     7    java.io.FileOutputStream.writeBytes
   0.2%     0  +     3    sun.misc.JarIndex.read
   0.2%     0  +     3    ec.Evolve.initialize
   0.1%     0  +     2    java.util.zip.ZipFile.initIDs
   0.1%     0  +     2    java.util.zip.ZipEntry.initIDs
   0.1%     0  +     2    java.util.zip.Inflater.inflateBytes
   0.1%     2  +     0    java.net.URLClassLoader.findClass
   0.1%     2  +     0    ec.gp.GPTree.deepClone
   0.1%     2  +     0    java.nio.Buffer.<init>
   0.1%     0  +     2    ec.Evolve.loadParameterDatabase
   0.1%     2  +     0    ec.util.RandomChoice.pickFromDistribution
   0.1%     0  +     2    ec.gp.koza.CrossoverPipeline.produce
   0.1%     1  +     0    sun.nio.cs.SingleByteEncoder.encodeLoop
   0.1%     0  +     1    ec.gp.GPIndividual.deepClone
   0.1%     1  +     0    java.lang.Package.isSealed
   0.1%     0  +     1    java.lang.Float.valueOf
   0.1%     0  +     1    ec.gp.GPInitializer.setupNodeConstraints
   0.1%     1  +     0    ec.gp.GPNode.depth
   0.1%     0  +     1    ec.simple.SimpleEvaluator.evaluatePopulation
   0.1%     1  +     0    java.lang.String.<init>
   0.1%     0  +     1    java.io.OutputStreamWriter.flush
10.7%    28  +   127    Total interpreted (including elided)

      Compiled + native   Method
   6.9%   100  +     0    ec.app.regression.func.Mul.eval
   5.7%    83  +     0    ec.app.regression.func.Sin.eval
   5.6%    81  +     0    vtable chunks
   4.8%    70  +     0    ec.gp.GPNode.numNodes
   4.5%    65  +     0    ec.app.regression.func.X.eval
   2.6%    38  +     0    ec.gp.GPNode.cloneReplacing
   2.6%    37  +     0    ec.app.regression.func.Add.eval
   2.1%    31  +     0    ec.app.regression.func.Sub.eval
   1.4%    20  +     0    ec.app.regression.Regression.evaluate
   1.3%    19  +     0    ec.app.regression.func.Exp.eval
   1.1%    16  +     0    ec.gp.GPNode.cloneReplacing
   0.8%    12  +     0    ec.gp.GPNode.nodeInPosition
   0.6%     8  +     0    ec.select.TournamentSelection.produce
   0.4%     6  +     0    ec.app.regression.func.Div.eval
   0.3%     5  +     0    ec.util.MersenneTwisterFast.nextInt
   0.3%     4  +     0    ec.gp.koza.CrossoverPipeline.produce
   0.2%     3  +     0    ec.gp.GPNode.swapCompatibleWith
   0.1%     2  +     0    java.io.PrintWriter.flush
   0.1%     2  +     0    ec.app.regression.func.Cos.eval
   0.1%     1  +     1    ec.app.regression.func.Log.eval
   0.1%     1  +     0    sun.nio.cs.StreamEncoder.flush
   0.1%     1  +     0    ec.gp.GPNode.atDepth
   0.1%     1  +     0     
ec.gp.koza.KozaStatistics.postEvaluationStatistics
   0.1%     1  +     0    java.nio.Buffer.position
   0.1%     0  +     1    ec.gp.GPNode.rootedTreeHashCode
42.7%   615  +     2    Total compiled (including elided)

          Stub + native   Method
21.7%    26  +   288    java.lang.Object.clone
   3.6%     0  +    52    java.io.FileOutputStream.writeBytes
   3.5%    17  +    34    java.lang.StrictMath.exp
   0.1%     0  +     2    java.lang.StrictMath.log
29.0%    43  +   376    Total stub

   Runtime stub + native  Method
   1.2%    18  +     0    new_object_array_millicode Runtime1 stub
   0.5%     7  +     0    slow_subtype_check Runtime1 stub
   0.1%     1  +     0    array_copy_2 Runtime1 stub
   1.8%    26  +     0    Total runtime stubs

   Thread-local ticks:
   0.1%     2             Blocked (of total)
   0.3%     5             Class loader
   0.1%     1             Interpreter
   2.5%    36             Compilation
12.0%   174             Unknown: running frame
   0.2%     3             Unknown: no last frame
   0.6%     8             Unknown: thread_state


Global summary of 28.16 seconds:
100.0%  2537             Received ticks
42.9%  1089             Received GC ticks
   1.9%    47             Compilation
   0.1%     2             Other VM operations
   0.2%     5             Class loader
   0.0%     1             Interpreter
   7.3%   185             Unknown code
geepers[~/ecj/ec/app/regression]>