>This has gotten to a point where the only sensible answer I can give is
>(1) take it to iteration 500
>(2) Start coverage logging
>(3) let it do the iteration
>(4) stop coverage logging
>
>Then see which parts take a long time

Attached please find comparisions. I run coverage for first 10 executions and last 10 executions. You can see that the difference is quite dramatic.

Here is the test program I ran:

oSEZ=newobject('basic_Tallying','tallyEz.prg')
*oSEZ=createobject('tallyez40.basic_Tallying')
&&set step on
IF VARTYPE(oSez) = 'O'

* tested already
*oSEZ.SetVerbosityLevel(val(inputbox('VerbosityLevel to run at','VBL','0',5000)))
oSEZ.ClearLog()
lcInvoke = '<func>getserverversion</func>'
*oSEZ.Invoke(m.lcInvoke)
  _VFP.AutoYield = .f.
  
FOR i = 1 TO 1000

IF i <=10 
  SET COVERAGE TO 'FastEvents.log' additive
ENDIF   
IF i> 10
  SET COVERAGE TO 
endif  
IF i >=990 
  SET COVERAGE TO 'SlowEvents.log' additive
ENDIF   


*!*	TEXT TO lcInvoke noshow
*!*	<func>GetItem</func><tcunitid>TMAN03</tcunitid><tcOperator>LBAILO</tcOperator><tcReturnType>XM3</tcReturnType><tcScan>71</tcScan>
*!*	ENDTEXT
*!*	oSEZ.Invoke(m.lcInvoke)

*!*	TEXT TO lcInvoke noshow
*!*	<func>GetItem</func><tcunitid>TMAN03</tcunitid><tcOperator>LBAILO</tcOperator><tcReturnType>XM3</tcReturnType><tcScan>090897504217</tcScan>
*!*	ENDTEXT
      DOEVENTS
 
*lcInvoke = '<func>GetServerVersion</func>'
oSEZ.Invoke(m.lcInvoke)

*!*	oSEZ.Invoke(m.lcInvoke)

*!*	TEXT TO lcInvoke noshow
*!*	<func>SubmitScan</func><tcunitid>TMAN10</tcunitid><tcOperator>MATT</tcOperator><tnLocationID>16</tnLocationID>
*!*	<ttScanDateTime>9/15/11 10:26:18 AM</ttScanDateTime><tcScan>049000003710</tcScan>
*!*	<tcDptCatItm>RT37SUNDRI071FOOD   3556      </tcDptCatItm><tnInventID>0</tnInventID><tnQty>12</tnQty><tnStatus>0</tnStatus>
*!*	<tnBatchNo>2602</tnBatchNo><ttbatchdt>
*!*	ENDTEXT
*!*	oSEZ.Invoke(STRTRAN(m.lcInvoke,'TMAN10','TMAN' + transform(m.i)) + TRANSFORM(DATETIME()) + '</ttbatchdt>')\
NEXT 
ENDIF 

SET COVERAGE TO

We see that write_log function time grew, Parse function time grew and even GetServerVersion time grew although this function code is very simple

procedure GetServerVersion() as string;
      helpstring "Version # gleaned from .DLL  Returns This.cServerVersion"

   this.write_log('Entering method...', program(), '1')
   this.write_log('Returning: '+ '0-'+this.cServerVersion, program(), '2')

   return this.RetValToSTR('0-' + this.cServerVersion)
   endproc

Although we see it calls the growing time write_log function first, so that may be the main reason. I can comment out this function and re-test, but I think I identified the main culprit for slowness is write_log function.

I look up this procedure and it stores every message in the property, so this property is going to grow more and more and therefore the execution time is going to slow down.

I'm not sure what can I do to not let it grow that much. Although I found one potential thing to make it run quicker and implemented it.