An interesting Kaffe execution profile

[David Young]

	The JDK interpreter out-performs Kaffe on programs
that create & discard a whole lot of objects. I decided
today to try and get to the bottom of this, so I built a
statically-linked Kaffe with execution profiling enabled.
I ran that Kaffe twice on a Java program that renders a
40x30 image of a complicated 3D object.

	Examining gprof's output on Kaffe's execution profile,
a few things stand out. First, the function named
gc_primitive_alloc consumes the most CPU time by far,
at 77.27 percent of the program's 7-minute duration:

(gprof output)

Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total           
 time   seconds   seconds    calls  us/call  us/call  name    
 77.27      0.17     0.17    17450     9.74     9.74  gc_primitive_alloc
  9.09      0.19     0.02       85   235.29   293.37  finishGC
  4.55      0.20     0.01 16701165     0.00     0.00  markObject
  4.55      0.21     0.01  7190125     0.00     0.00  objectStatsChange
  4.55      0.22     0.01  2499153     0.00     0.00  findMethodLocal
  0.00      0.22     0.00 21771033     0.00     0.00  intsRestore
  0.00      0.22     0.00  7234508     0.00     0.00  jmutex_lock
  0.00      0.22     0.00  7234506     0.00     0.00  jmutex_unlock
  .
  .
  .
  0.00      0.22     0.00    15932     0.00     0.00  gc_primitive_free
  .
  .
  .

	I think it's interesting to compare how much time gc_primitive_free
takes with gc_primitive_alloc. My intuitive feeling is that
gc_primitive_free and gc_primitive_alloc should take approximately the
same amount of time during the execution of my program. I wonder if there
is a bug in one of them?

	It would appear from looking at the profiling output that the
program ran for about 1/5th of a second, but it actually ran about
7 minutes. Can anyone offer an explanation of this discrepancy?

	I've made the complete execution profile that gprof generated
available at http://www.uni.uiuc.edu/~dyoung/prof.txt , should
anyone want to take a closer look at it.

	If you think these profiling results might be in error please
let me know!

	The next step is to look and see what gc_primitive_{alloc,free}
are doing by observing Kaffe's debug output. It appears that
compiling Kaffe with DEBUG #defined causes a whole lot of
errors. Is there a patch that fixes this?

Dave


-- 
David Young * dcy2 cornell edu