Skip to main content
B
Bart_Vanhulle
Participating Frequently
November 23, 2009
Answered

Repeated Call to CFC function is much slower than UDF version

  • November 23, 2009
  • 2 replies
  • 1339 views

For a project we were confronted with an unexpected behaviour from a CFC. Without going to much into the details of the project it comes down to the following: when we run through a set of records, let's say 100, and apply a formatting function on it, the overhead is 4-5 extra seconds when we call it from an instantiated component (only once) compared to when we hardcode it as a UDF. Since our application can process several thousands of records in 1 pass the overhead quickly goes over 100 seconds compared to the UDF.

I was wondering if there's any logical explanation to this behaviour. From what I understood a function called from a component shouldn't add any noticeable overhead after the component has been instantiated.

Our setup is a Coldfusion 8 Jrun installation running on Linux. We couldn't really find anything on the web documenting this (or what we found told us there shouldn't be any extra overhead). We could change the function call to a UDF call but we prefer to keep it in a CFC as there's more going on behind the scenes than just formatting the data.

B.

This topic has been closed for replies.
Correct answer ilssac

I ran the test now from 3 different servers, 2 Linux servers (fully licensed) and 1 windows server (developer edition) and the results are the same. All 3 servers run CF8. The UDF version is 40 times faster than the CFC version. The CFC on the windows server is slightly faster than on the Linux servers, but it's still 30 times slower than the UDF.

We don't have a CF9 installation so can't test on that.

B.


HA!  Cool!!!! I Think I solved something, I feel so proud.

I run Adam's code and the first time I ran it I was getting results similar to Biebel3.  But it was curious, I had debug output showing it it was not showing where the time was being spent.  It would show nearly 2 full seconds to generate the CFC page, but the components broken down in the debugging table only added up to about 50 milliseconds.

I first tired putting a <cfsetting showdebugoutput="no"> on the top of the CFC page, but that did not change the results.  Because even if you don't show the results, ColdFusion still complies the debugging output.  So I went into the Administrator and actually turned off the debugging feature.

Viola, I started getting the results posted by Adam.

It looks like this is an issue where it takes a lot of overhead for ColdFusion to compile a debugging record for each and every CFC call in that large loop.

The good news, this is a darn easy fix for a production system!

2 replies

BKBK
Community Expert
BKBKCommunity Expert
Community Expert
November 23, 2009
we call it from an instantiated component (only once)

Check to make sure this doesn't happen in a loop. If it does, you will be instantiating the component once, a thousand times.

B
Bart_VanhulleAuthor
Participating Frequently
November 23, 2009

The loop was the first thing we checked. We're certain the component(s) are only instantiated once.

B.

ilssac
ilssac
Inspiring
November 23, 2009

It shouldn't unless the way you coded the CFC causes it to do so.

It would depend on how you instainate the CFC, what scope you instinate the CFC in, and what the CFC does with memory every time it is called.

B
Bart_VanhulleAuthor
Participating Frequently
November 23, 2009

Thank you for the reply. The CFC is instantiated using CFScript, before the loop starts. It's stored in the Variables scope for usage in a component. A quick version of the script would look like this:

Variables.MyCFC = CreateObject("component","MyCFC");

function test(arr) {

for ( i = 1; i < ArrayLen(arr); i++) {

x = Variables.MyCFC.format(arr);

}

}

The format function we tested with in the MyCFC component looks like this:

function format(s) {

    return s;

}

This is a very basic test case we used to validate the problem. If the format function is in the same page as where the loop is, every 100 records it's 4 seconds faster than when it's invoked from the CFC (the 'real' overhead with the UDF being less than 100ms). Pulling it out of the Variables scope didn't make a difference either.

Perhaps we missed something related to memory consumption, but we figured this is the correct way to do what we had in mind. We doubt it's the extra methods and data in the CFC as we noticed similar processing result times with just the format function in the component.

B.

A
Adam Cameron.
Inspiring
November 24, 2009

I ran a test with the following code:

// MyCFC.cfc

component {

    function format(s) {
        return s;
    }

}

<!--- runCfc.cfm --->

<cfscript>
// make an array to test with
a = [];
for (i=1; i <= 10000; i++){
    a = repeatString(chr(randRange(65, 90)), 100);
}


Variables.MyCFC = CreateObject("component","MyCFC");

function test(arr) {
    for ( i = 1; i < ArrayLen(arr); i++) {
        x = Variables.MyCFC.format(arr);
    }
}

iStart = getTickCount();
test(a);
writeOutput("Runtime: #getTickCount()-iStart#");
</cfscript>

<!--- runUdf.cfm --->

<cfscript>
// make an array to test with
a = [];
for (i=1; i <= 10000; i++){
    a = repeatString(chr(randRange(65, 90)), 100);
}


function format(s) {
    return s;
}
   
function test(arr) {
    for ( i = 1; i < ArrayLen(arr); i++) {
        x = format(arr);
    }
}

iStart = getTickCount();
test(a);
writeOutput("Runtime: #getTickCount()-iStart#");
</cfscript>

The only real difference between runCfc.cfm and runUdf.cfm being the former uses the CFC method, the latter a UDF (same function though).


My results were that over multiple passes, the CFC version averaged around 180ms, and the UDF version 140ms.  Over 10000 iterations, that difference only really registers as "trivial" to me.

I'm concerned that you are seeing a 4sec difference over 100 iterations.  4sec is huge.

Can you pls create a stand-alone, self-contained, completely functional bit of code that demonstrates this (along the lines of what I've posted above)?  I think there's something else to it.

--

Adam

Terms & ConditionsAccessibility statement
Using the community Terms of use Privacy Cookie preferences Do not sell or share my personal information ad choicesAdChoices