Orange is my favorite color

It’s pretty common knowledge that the Java 6 JRE in ColdFusion 8 has a bug from Sun that makes loading CFC-heavy applications slow. This impacts most framework-based apps that use Model-Glue, Mach-II, Coldspring, Transfer and so forth. To be clear, it’s not the frameworks, it’s a bug in the underlying Sun JRE.

I have some timing in my Application.cfc and index.cfm in my model-glue app that produced some interesting results different from my expectations. The difference is between reinitializing an application on a running CF8 server and starting up the CF8 server from scratch. I track the time it takes to load beans into Coldspring and for Model-glue to initialize with the following code in application.cfc:

<cfset cnt = getTickCount() />
<cfset application.cs.loadBeansFromXmlFile(expandPath("coldspring.xml"), true) />
<cflog file="application" type="information" text="Finished ColdSpring load in #(getTickCount()-cnt)/1000# seconds" />

And in index.cfm:

<cfif NOT structKeyExists(application, ModelGlue_APP_KEY)>
<cfset booInit = true />
<cfset cnt = getTickCount() />
<cfelse>
<cfset booInit = false />
</cfif>

<cfinclude template="/ModelGlue/unity/ModelGlue.cfm" />
<cfif booInit>
<cflog type="information" file="application" text="ModelGlue #ModelGlue_APP_KEY# initialized in #(getTickCount()-cnt)/1000# seconds" />
</cfif>

Now my expectation is that it would be slower on a cold start to load these applications than restart but the reverse is what I see by a factor of 2-1. My reinit routine performs the following:

  • Clears session key
  • Clears trusted cache via Admin API
  • Clears Transfer cache
  • Deletes Coldspring instance
  • Recreates Coldspring instance (this is timed)
  • Clears all Model-glue Application keys to force reload
  • Reinitialized session
  • Runs index.cfm to initialize Model-Glue (this is timed)

The times below are from starting CF8, loading my application home page, then immediately performing a warm reinit:

Cold Start   Warm Reinit   Ratio
Coldspring   20.7s 48.2s 2.3x
Model-Glue   29.3s 55.8s 1.9x

Anyone know why this would be the case? I would think the classes had already been loaded so a warm reinit should be faster than the cold start.

If this is true in general, then it’s better to restart the CF8 server when deploying code than running a reinit procedure.

7 Comments

  1. Dan G. Switzer, II said:

    on July 2, 2008 at 6:28 am

    @Brian,

    If you have a large number of objects, I suspect the slow down may be due to memory management. If the JVM’s being forced to do several garbage collections during the reinit stage, that could explain for the difference in performance.

  2. Tim Elsner said:

    on July 2, 2008 at 7:50 am

    I dont have any hard numbers, but I’m pretty sure I’m experiencing the same thing on my MG site. With CF7, I had no problems deploying new code during the day by doing a reinit. Ever since the switch to CF 8, I wait until after hours and restart CF to deploy new code.

    I’ve thought about trying to tune the JVM, but have not found the time yet.

  3. Elliott Sprehn said:

    on July 15, 2008 at 11:18 pm

    “Clears trusted cache via Admin API”

    I’m reasonably sure that right there is why the warm reinit is slamming you so hard.

    The classes aren’t already loaded after clearing the trusted cache, instead CF dumps all the classes loaded into memory and reloads every single one of them.

    There’s a class generated for every .cfm and .cfc file, and another one for every UDF in your entire application.

    Try running these reinit’s over and over again. I have a feeling they’ll get slower and slower with each one.

  4. brian said:

    on July 15, 2008 at 11:26 pm

    @Elliott – the times quoted above are wrapped specifically around the Coldspring startup and the Model-Glue instantiation. While it does clear the trusted cache, I think the times above should be analogous to a cold restart in terms of class generation. Restarting CF is the equivalent to clearing the trusted cache AFAIK.

  5. Elliott Sprehn said:

    on July 15, 2008 at 11:33 pm

    @Brian

    That’s not how the class loader bug works. The more classes you load, the worse it gets.

    So when CF first starts not a lot of classes have been loaded, so not a big deal. But as you restart your applications that generates more and more classes, over and over again.

    CS and MG generate *tons* of classes, one for every single CFC and method on each of those CFCs for the entire framework.

    The modelglue/unity/framework/ModelGlue.cfc alone generates 43 classes.

  6. brian said:

    on July 16, 2008 at 12:59 am

    @Elliot – In terms of the class loader, is it over the lifetime of the JVM or are we talking about the classes that CF has currently generated and loaded? If the former, then that explains why the reinit is slower than the initial startup even when performed immediately on load. This just goes to further solidify that the initial load of CF applications on JVM 1.6 in production aren’t a problem if you can bounce the server. On the cold start it’s only mildly slower than my CF7 install.

  7. Elliott Sprehn said:

    on July 16, 2008 at 6:45 am

    @Brian

    The former (ie lifetime of the JVM). As far as I know the bug is down in the belly of the JVM in some dependency checking code written in C++.

    So yeah, if you can restart the server the hit isn’t nearly as bad as it would be if you had to warm restart.

    Of course that still depends on how fast your machine is and how much RAM you have. Even a cold start can be painfully slow if you generate enough classes, or your hardware isn’t that great.

{ RSS feed for comments on this post}