[kepler-dev] Kepler Startup times

[Dan Higgins]

Hi All,

Below is a brief memo I put together with some Kepler startup times 
under various conditions and some observations about those times. What 
is interesting is just how long a cold start with no cache takes (the 
case for the first time Kepler user). It appears to me that the startup 
time depends on both the time to build the actor cache and to build the 
actor library (tree).

Dan

---




Kepler Startup Time

It is recognized that Kepler can take a long time to startup. It has 
been thought that much of this time is
due to the building of the Actor library (i.e. the actor tree on the 
left of the Kepler window).

The primary class where the building of the Actor library occurs in 
org.kepler.moml.KSWLibraryBuilder. I put
some timing statements into the code for this class and measured the 
times shown in the table below. (3GHz
Pentium, Windows XP, Java 1.5)



                                        ColdStart       WarmStart       
ColdStart          WarmStart
                                        (no cache)      (no cache)      
(with cache)       (with cache)

1) KSWLibraryBuilder.buildLibrary        56.0 sec           
20.3          34.2               13.0
2) buildingKSWLibrary                    51.4               
17.4           2.3                0.8

1) with single actor                     6.2                
3.9            -                  3.5
2) with single actor                     2.0                
0.8            -                  0.1


The times for 1) KSWLibraryBuilder.buildLibrary are basically the time 
for the entire buildLibrary method of
the KSWLibraryBuilder class. The times labeled 2) buildingKSWLibrary are 
for just part of that method -
namely the part that reads KAR files and adds information from those KAR 
files to the cache (in the .kepler
file). Note that the times for 2) are included in the times given for 1).

It is important to recognize that the buildLibrary method actually does 
two tasks. KAR files are stored in
various directories. (These KAR files are built by the 'ant 
buildkarlib'.) The section of code under item 2)
in the table scans these directories, unzips the kar files, and puts the 
contents into the Kepler cache
database. As part of doing so, the moml of each actor/director is parsed 
using the MOML parser.

The second task that is done is the actual creation of the actor library 
(the tree model for the actor tree).
Note that the time to create this model is the difference between time 
1) and 2).

The 'ColdStart' columns are times for the operation immediately after 
startup of the machine. The operating
system has thus had no chance to cache any files. The 'WarmStart' 
columns are for executions after the inital
one. WarmStarts take significantly less time than ColdStarts. The only 
reason I can think of for this is OS
caching of all the jar files that Kepler loads. The 'no cache' and 'with 
cache' qualifiers refer to the
Kepler cache (not the OS file cache) in the .kepler directory. 'no 
cache' refers to starting execution with
no .kepler directory. This forces the code to go through all the saved 
kar files and save actor information
in the kepler cache. 'with cache' means the keple actor cache has 
previously been built.

The 'with single actor' rows refer to a test case where only a single 
actor is in the kar file list, while
the original times include loading the 300+ full list of Kepler actors.

The worst case is obviously the Cold Start with no cache which takes 56 
seconds. Unfortunately, this is the
first case seen by a new user with a newly installed version of Kepler! 
Note that most of this time is spent
in reading the kar files and building the KSW library in the Kepler 
cache (51.4 sec). It takes only an
additional 4.6 seconds to build the actor library for the tree! Compare 
these times to the WarmStart (no
cache) case. This case takes only 20.3 seconds with 17.4 of that used to 
build the cache. Note that the Java
code of Kepler is doing exactly the same things in the ColdStart and 
WarmStart cases! So the only thing I can
think of to explain the difference is the OS has cached the large number 
of jar files that Kepler must access
in going through the actor KAR files.

A second interesting point is how long it takes to build the actor 
cache. Each kar file is read and the moml
description of the actor is parsed using the Moml parser. But the 
ActorMetadata class turns the data back to
a moml string when the ActorCacheObject class sends it to the cache! (I 
am not sure the moml saved in the
cache is identical to that inside the kar. If it is, we can skip the 
parsing and then conversion back to xml
here!)

Note that the creation of the actor library tree requires reading the 
moml from the cache and parsing it
again using the Moml parser. So we are really parsing things twice with 
a ColdStart! Apparently the Moml
parser also loads all classes referenced in the moml (i.e. all the actor 
classes). It is not clear whether
parsing the Moml itself is what takes the majority of the time or 
whether loading all the classes specific to
the actors is the big time consumer

-- 
*******************************************************************
Dan Higgins                                  higgins at nceas.ucsb.edu
http://www.nceas.ucsb.edu/    Ph: 805-893-5127
National Center for Ecological Analysis and Synthesis (NCEAS) Marine Science Building - Room 3405
Santa Barbara, CA 93195
*******************************************************************