I repeatedly used the Progress Profiler to measure execution times and in particular the overhead for the call as identified by the Profiler.
The measurements were done by repeatedly looping over 20,000 rows. In other words, the overhead as reported by the Profiler are averaged over 200,000 calls.
The reason I am interested in these numbers is to understand the peformance of OO ABL since there are instances in our industry that we might call some methods a few million times.
What is surprising is the overhead of calling a overriden method in a instantiated object as in CASE 2 below: About 1.097 milliseconds.
This is stark contrast to calling either a static method or a method in the super class in which case there is a difference of two orders of magnitude.
1.097 milliseconds versus .012 milliseconds.
Are others seeing the same results? these numbers hold true, even if we don't pass any parameters into the method.
Does Progress have any tools to show what exactly is happening in each case (are virtual tables being used for lookup for example)?
CASE:
1. Invoking super parent class method
.000012 seconds overhead
2. Invoking another method in different instantiated object using NEW() (object instantiated is a subclass with the method overriden)
.001097 seconds overhead
3. Invoking another static method
.000097 seconds overhead and other times
.000018 seconds overhead
4. Invoking external procedure
.000093 seconds overhead
Would you mind sharing code? And Progress version.
Yes, code specifics and version and some clarification of case #2, please. Also, some clarification of exactly what you mean by "overhead".
I will say that I have previously reported that there is an unexpected performance penalty in using inheritance. I have not retested this in 11.0, though.
You also might want to move the discussion to the OO forum under OpenEdge to get the right audience.
Progress version: 10.2B03
Overhead: This is the average overhead as reported by the Progress Profiler. I assume this is the overhead to call the method/external procedure/etc.
Per Profiler documentation, it is:
"Where LineNo is 0, that refers to the time used to initialize and then later to tear down
the procedure or trigger. This is the overhead of running the
procedure/function/trigger."
The pattern for relative run times between different kinds of calls are true over 30 or 40 runs that I have done. This is a concern before we go further into OOABL.
Case 1: When method called is part of object constructed using NEW ()
/* overhead is at least 10X higher when compared to calling a method that is say part of the parent class or a method which is static*/
Therefore:
oViewerClass = new ViewerClass().
for each someTable:
/* overhead in latest measurement is: .000311 seconds per one call */
oViewerClass:writeBuffer (bufferhandle to SomeTable).
/* overhead to call this static helper method: .000079 seconds */
vchardigits = utils.getDigitsOnly(vchardigits).
/* overhead to call a method in the parent class: .000016 seconds */
this-object:addsubTotal().
/* overhead to call external procedure: .000047 */
run COUNTRYISO2.P(input vcntry,
output vCntryISO2,
output vCntry).
end.
/* actual method called*/
270 method public override logical writeBuffer(input pHBuffer as handle):
271
272 if (pHBuffer:available) then
273 do:
274 for each ttOutStream no-lock :
275 vCharBuffer = "".
276 ttOutStream.hbuf:buffer-copy(pHBuffer).
277
278 do i = 1 to ttOutStream.hbuf:num-fields:
279
280 pFBuffer = ttOutStream.hbuf:buffer-field(i).
281
282 vReportValue =
283 if (pFBuffer:label > "") then
284 DYNAMIC-INVOKE(pFBuffer:label,
285 "format",
286 input pFBuffer:buffer-value,
287 input pFBuffer:format)
288 else
289 if (pFBuffer:buffer-value <> ?) then
290 pFBuffer:string-value()
291 else
292 if pFBuffer:data-type = "date" then "00000000"
293 else
294 fill(" ",integer(pFBuffer:width-chars)).
295
296 vCharBuffer = vCharbuffer + vReportValue +
297 ttOutStream.columnDelimiter.
298 end. /* do i = */
299
300 if (ttOutStream.columnDelimiter <> "") then
301 vCharBuffer = substring(vCharbuffer,1,
302 length(vCharBuffer) - 1).
303 if ttOutStream.upperCase then
304 /* the higher CASE configurations take over if set */
305 vCharBuffer = CAPS(vCharBuffer).
306
307 put stream-handle ttOutStream.hStream unformatted
308 vCharBuffer skip.
309 end. /* for each*/
310
311 end. /* if available */
312 end method.
Discussion continued on the OOP forum.
http://communities.progress.com/pcom/thread/47294?tstart=0