2ms per call, or 2ms for all 500 calls?
In my tests, a straight up getMetaData() call on a CFC takes from 1 to 2 ms. That’s with CF8 on my local machine with a 512mb heap.
That seems blazingly fast, but the slow-down seems to creep up on you. I wanted to see how often getMetaData was being called on an average page in my site so I did a find and replace on the coldbox/system folder and replaced getMetaData() with $getMetaData(). I then placed the following code in ColdFusion’s root component.cfc (ColdFusion8\wwwroot\WEB-INF\cftags):
The following test code showed me how many meta data calls it takes to create an instance of one of my beans:
#request.MDCount#My average bean requires 25-50 calls to getMetaData to return a wired instance.
Then I added the following code in my app’s application.cfc:
request.MDCount: #request.MDCount#It jacks with ajax calls, but for the most part the bottom of every page will tell you have many times getMetaData was called for that request.
I found that the average page on my site calls it between 500 to 700 times with production settings. (handler, config, and model object caching turned on, etc) There are several places in the CB framework that use getMetaData, but the large majority of the calls are from within the beanfactory. (Note, I was trying this out on RC1) That means roughly half a second to 1 second worth of getMetaData calls are happening on every page if you go with 1-2ms per call. That’s adding up kind of quickly!
Now, I have removed a LOT of of object instances on my site in favor of result sets when dealing with more than a few dozen results. However, in part of the back-end admin portion of my site I have some old screens I wrote very early-on in my foray into OO programming where EVERYTHING is objects. One particularly slow screen is a user search. If I run a search that returns about 300 users, it creates a single Iterating Business Object for all the users, creates the membership object for each user, the company object for each user, and a communication object so it can output the result list with a collection of relevant user data. (The composite objects are all lazy loaded as the getters are called which brings up it’s own issues of numerous queries being ran to “lazily” piece-meal all the data together)
So, after creating 3 beans for each result that’s returned, for about 300 results, I’ve created about 900 wired objects via the bean factory. in this example, these are fairly simple objects with little autowiring required and they only require about 20 getMetaData calls apiece, but that’s still about 17,000 calls to getMetaData on this page which is going to cost at least 17 seconds. Interestingly enough, in this specific test there was about 5 seconds worth of database calls, and the total request took 22 seconds. That means the remaining 17 seconds was pretty much entirely consumed by getMetaData calls.
And, as usual, a very large portion of the stack traces were spent on
java.io.WinNTFileSystem.getLastModifiedTime as a part of a getMetadata() call.
What’s very interesting to note is that turning on trusted cache on my workstation cuts the getMetaData call times IN HALF. That is very re-assuring since I run with trusted cache on in production, but what is frustrating about that is, even with trusted cache on, the majority of getMetaData() calls are spent on java.io.WinNTFileSystem.getLastModifiedTime. I don’t know if that’s a CF bug, but I wouldn’t say it’s right.
So, all that being said I’m not sure entirely where to go with all this information. The example of the user search can easily be dismissed as an inappropriate way to use objects in CF. That may or may not be true, but I think it does a good job of showing on a larger scale the performance bottle necks that still exist everywhere else in my app on a smaller scale. Remember, I still have 500-700 getMetaData calls on every page of my production site. That sets a pretty high floor of the fastest my pages can ever become. (.5 to 1 second)
I haven’t gotten a chance to review any of your wirebox changes on SVN yet. As far as your specific example of getMetadata(arguments.target).name, I recognize that from a the autoWire method in the beanFactory code I’ve looked at before.
Is it possible the calling function can pass along an optional parameter that describes the name of the object if the calling code is privy to that information. Then you can resort to getMetaData() only when necessary. If I recall, autoWire is almost always called from getModel and getModel should already know the name of the CFC.
Thanks for your work looking in this, Luis!
~Brad