Scripting Efficiency

Recently we wrote and article on “How can I get the text for a category” and a comment was raised that it was not perhaps the best way and the fastest way to write that particular routine. The comments where well founded and raised an important topic in our minds as to how things should be written and the effect on performance that a badly written function could have on your script. This article takes the script and does some analysis to see just how slow it is.

To get this article started we need some metadata, so open up mrStudio and create a mdd file with the following code in it.

Metadata(en-AU, Question, Label)
    DidDo "What did you do on the weekend"
    categorical [1..]
    {
    A "A", B "B", C "C", D "D", E "E", F "F",
    G "G", H "H", I "I", J "J", K "K", L "L",
    M "M", N "N", O "O", P "P", Q "Q", R "R",
    S "S", T "T", U "U", V "V", W "W", X "X",
    Y "Y", Z "Z"
    };
End Metadata

Then enter , in the routing section the script that we need to test.

Dim oParent,oCats,oCat
Dim iTimes,sValue,iLoop,iLoopMax
Dim oStart, oEnd,oTot,sTest,iMax
Dim oTimer

DidDo.Response.Value = "{a,b,c,d,e,f,g,h,i,j,k,l,m,n,o,p,q,r,s,t,u,v,w,x,y,z}"

iMax = 100
iLoopMax = 10
oTot = 0.000

For Each oParent in Iom.Questions
Select Case oParent.QuestionType
Case QuestionTypes.qtLoopCategorical, QuestionTypes.qtLoopNumeric
' I have children ( Grid / Loop)
Case QuestionTypes.qtBlock, QuestionTypes.qtCompound, QuestionTypes.qtPage
' I have children
Case = QuestionTypes.qtSimple
' I don't have children
Select Case oParent.QuestionDataType
Case Is = DataTypeConstants.mtCategorical
For iLoop = 1 to iLoopMax
oStart = Now()
For iTimes = 1 to iMax

sValue = CTEXT(oParent.Response.Value)
sValue = Replace(sValue,"{","")
sValue = Replace(sValue,"}","")
oCats = Split(sValue,",")
For each oCat in oCats
debug.echo(oParent.Categories[CCategorical(oCat)].Label)
Next

Next

oEnd = Now()
oTot = oTot + clong(oEnd) - clong(oStart)
sTest = sTest + CTEXT(oStart) + ":" + CTEXT(oEnd) + _
" : Time in Seconds (TEST 1) :" + CTEXT(clong(oEnd) - _
clong(oStart)) + mr.NewLine
Next
Case Else
debug.log( CTEXT(oParent.response.value) )
End Select
End Select
Next

Debug.Log(sTest)
Debug.Log("AVG:" + CTEXT(oTot /iMax))

sTest = ""
oTot = 0.000
For Each oParent in Iom.Questions
Select Case oParent.QuestionType
Case QuestionTypes.qtLoopCategorical, QuestionTypes.qtLoopNumeric
' I have children ( Grid / Loop)
Case QuestionTypes.qtBlock, QuestionTypes.qtCompound, QuestionTypes.qtPage
' I have children
Case = QuestionTypes.qtSimple
' I don't have children
Select Case oParent.QuestionDataType
Case Is = DataTypeConstants.mtCategorical
For iLoop = 1 to iLoopMax
oStart = Now()
For iTimes = 1 to iMax

For each oCat in oParent.response.value
debug.echo(oParent.Categories[CCategorical(oCat)].Label)
Next

Next

oEnd = Now()
oTot = oTot + clong(oEnd) - clong(oStart)
sTest = sTest + CTEXT(oStart) + ":" + CTEXT(oEnd) + _
" : Time in Seconds (TEST 1) :" + CTEXT(clong(oEnd) - _
clong(oStart)) + mr.NewLine
Next
Case Else
debug.log( CTEXT(oParent.response.value) )
End Select
End Select
Next

Debug.Log(sTest)
Debug.Log("AVG:" + CTEXT(oTot /iMax))
We have created two loops, now in this case the reason we have created two loops is to get some average times. This script only takes a few seconds to run, so we need to increase the time it takes to actually get a good recoding of the time take. So we have two controlling variables that we can play with. The first is iMax. This is used to just run the command X times and in our case we have set this two 100. The second is iLoopMax and this is used to control how many times that function is run, you could think of this as the number of people that are running the first loop one after the other. So the more we increase iLoopMax the more rows of results we will get to produce an average with.

Caution : If you change the values of iMax and Iloop to much you will
encounter the following error
Critical Error : Infinite loop detected. The number of opcodes executed has 
    exceeded the max opcodes value

This means that mrInterview / mrStudio has detected an infinite loop, well it thinks it has , and is terminating the script. This prevents your survey from causing massive strain on your mrInterview servers.
When we run the script you will see in the output window the following text.

01/11/2008 11:08:00 AM:01/11/2008 11:08:00 AM : Time in Seconds (TEST 1) :0
01/11/2008 11:08:00 AM:01/11/2008 11:08:00 AM : Time in Seconds (TEST 1) :0
01/11/2008 11:08:00 AM:01/11/2008 11:08:01 AM : Time in Seconds (TEST 1) :0
01/11/2008 11:08:01 AM:01/11/2008 11:08:01 AM : Time in Seconds (TEST 1) :0
01/11/2008 11:08:01 AM:01/11/2008 11:08:01 AM : Time in Seconds (TEST 1) :0
01/11/2008 11:08:01 AM:01/11/2008 11:08:02 AM : Time in Seconds (TEST 1) :0
01/11/2008 11:08:02 AM:01/11/2008 11:08:02 AM : Time in Seconds (TEST 1) :0
01/11/2008 11:08:02 AM:01/11/2008 11:08:02 AM : Time in Seconds (TEST 1) :0
01/11/2008 11:08:02 AM:01/11/2008 11:08:03 AM : Time in Seconds (TEST 1) :0
01/11/2008 11:08:03 AM:01/11/2008 11:08:03 AM : Time in Seconds (TEST 1) :0
AVG:0
01/11/2008 11:08:03 AM:01/11/2008 11:08:03 AM : Time in Seconds (TEST 2) :0
01/11/2008 11:08:03 AM:01/11/2008 11:08:04 AM : Time in Seconds (TEST 2) :0
01/11/2008 11:08:04 AM:01/11/2008 11:08:04 AM : Time in Seconds (TEST 2) :0
01/11/2008 11:08:04 AM:01/11/2008 11:08:04 AM : Time in Seconds (TEST 2) :0
01/11/2008 11:08:04 AM:01/11/2008 11:08:04 AM : Time in Seconds (TEST 2) :0
01/11/2008 11:08:04 AM:01/11/2008 11:08:05 AM : Time in Seconds (TEST 2) :0
01/11/2008 11:08:05 AM:01/11/2008 11:08:05 AM : Time in Seconds (TEST 2) :0
01/11/2008 11:08:05 AM:01/11/2008 11:08:05 AM : Time in Seconds (TEST 2) :0
01/11/2008 11:08:05 AM:01/11/2008 11:08:06 AM : Time in Seconds (TEST 2) :0
01/11/2008 11:08:06 AM:01/11/2008 11:08:06 AM : Time in Seconds (TEST 2) :0
AVG:0 

You will see, depending on the speed of your machine that each individual process too 0 seconds to complete. Now you will probably be thinking that this is good, my script does not take long to execute at all, but lets look at it in a little bit more. Firstly we can see that if we take the first start time of test 1 “01/11/2008 11:08:00” and the last end time of test 1 “01/11/2008 11:08:03” the whole thing took 3 seconds. Doing the same thing with Test 2 we get the same result of 3 secs, so does this mean that they run at the same speed? Well , not really , it shows that they are close, but how could 7 lines of code ( test 1 )
 

sValue = CTEXT(oParent.Response.Value)
sValue = Replace(sValue,"{","")
sValue = Replace(sValue,"}","")
oCats = Split(sValue,",")
For each oCat in oCats
    debug.echo(oParent.Categories[CCategorical(oCat)].Label)
Next

Be faster than 3 lines of code.

For each oCat in oParent.response.value
    debug.echo(oParent.Categories[CCategorical(oCat)].Label)
Next

Our problem is that the method we are using to record the time is not fine enough, so what we need to do is to record the time in mille-seconds. So because mrStudio / vba does not support this accuracy  in recording time we need to create a COM dll with something like visual studio or visual basic 6 , that allows us to record time in mille-seconds. To do this we used vb6 and created a dll with the following code in it.
 

Option Explicit
Private Type SYSTEMTIME
wYear As Integer
wMonth As Integer
wDayOfWeek As Integer
wDay As Integer
wHour As Integer
wMinute As Integer
wSecond As Integer
wMilliseconds As Integer
End Type

Private Declare Sub GetSystemTime Lib "kernel32" _
(lpSystemTime As SYSTEMTIME)

Public Function TimeToMillisecond() As String
Dim sAns As String
Dim typTime As SYSTEMTIME
Dim iHour As Long
Dim iMins As Long
Dim iSecs As Long
Dim iTot As Long
Dim smSecs As String

On Error Resume Next
GetSystemTime typTime
iHour = Hour(Now) * 60 * 60 * 1000
iMins = Minute(Now) * 60 * 1000
iSecs = Second(Now) * 1000
smSecs = typTime.wMilliseconds

iTot = iHour + iMins + iSecs + typTime.wMilliseconds
sAns = Format(iTot, "")

TimeToMillisecond = sAns
End Function

Once created we changed our code to the following on both tests

oStart = oTimer.TimeToMillisecond()
.....
oEnd = oTimer.TimeToMillisecond() 

And when you run the script again you will see your output is something like this.
 

45359749:45360077 : Time in Seconds (TEST 1) :328
45360077:45360405 : Time in Seconds (TEST 1) :328
45360405:45360733 : Time in Seconds (TEST 1) :328
45360733:45361046 : Time in Seconds (TEST 1) :313
45361046:45361358 : Time in Seconds (TEST 1) :312
45361358:45361686 : Time in Seconds (TEST 1) :328
45361686:45361999 : Time in Seconds (TEST 1) :313
45361999:45362327 : Time in Seconds (TEST 1) :328
45362327:45362640 : Time in Seconds (TEST 1) :313
45362640:45362968 : Time in Seconds (TEST 1) :328
AVG:32.19
45362968:45363280 : Time in Seconds (TEST 2) :312
45363280:45363577 : Time in Seconds (TEST 2) :297
45363577:45363890 : Time in Seconds (TEST 2) :313
45363890:45364202 : Time in Seconds (TEST 2) :312
45364202:45364515 : Time in Seconds (TEST 2) :313
45364515:45364811 : Time in Seconds (TEST 2) :296
45364811:45365124 : Time in Seconds (TEST 2) :313
45365124:45365421 : Time in Seconds (TEST 2) :297
45365421:45365733 : Time in Seconds (TEST 2) :312
45365733:45366030 : Time in Seconds (TEST 2) :297
AVG:30.62

And now we can clearly see that the second test is faster. Again the number is not very big and you might say it should not matter because it is such a small number, and in a way you are right, but just think that if all your surveys have a slow way of writing something in them, then you are causing un-necessary strain on your servers.

This has been a very interesting article to write and we would be interested in testing other routines that you may have, so if you have something that you would like sped up then add a comment to this article and we will be intouch.

1 thought on “Scripting Efficiency”

  1. I want to access method of object after createobject function but showing error :
    “The ‘.xxxx’ type does not support the ‘zzzzzz’ method and a function of the same name does not exist”
    DLL created with Visual Basic, DLL is registered and don’t know where can be problem

Leave a Comment

%d bloggers like this: