More benchmarks: Storing variables

[wolph42]

Yesterday I've ran some benchmarks to check which way is best to store large amounts of variables on a lib token. I've tested
- creating packages (json object and strprop list, both in a classic way and using strformat)
- storing vars on the lib (as json, as strProp list and seperately)
- retrieving vars from the lib (and turning them back into vars).

Here's the test code (tested in build 87):
(Note that in the long loops I removed the 'save to lib token' part because its really slow. Also note that to increase the loop count you only need to increase the 'x' in the beginning)

benchmark code

Code: Select all

[h:'<!------------------------------------ INITIALIZE --------------------------------------------->']
[h: cif.stopwatch.end()]<tr><td>
[h: cif.stopwatch.setRegister("E")]
[h: cif.stopwatch.clearTotal()]
[h:theList = "test0,test1,test2,test3,test4,test5,test6,test7,test8,test9"]
[h,foreach(item,theList):set(item, roll.count)]
[h:y=2]
[h:x=1000]

<tables>

[h:'<!------------------------------------ CREATE --------------------------------------------->']
[h:'<!-- Create method 1: set json object with the help of strformat -->']
[h: cif.stopwatch.start()]
[h,count(y), CODE:{[count(x), CODE:{
	[h:testJson = strformat('{"test0":"%{test0}","test1":"%{test1}","test2":"%{test2}","test3":"%{test3}","test4":"%{test4}","test5":"%{test5}","test6":"%{test6},"test7":"%{test7}","test8":"%{test8}","test9":"%{test9}"}')]
}]}]
[h: cif.stopwatch.end()]<tr><td>
set json object with strformat </td><td> : [r: cif.stopwatch.getTime()]s</td></tr><br>

[h:'<!-- Create method 2: set json object -->']
[h: cif.stopwatch.start()]
[h,count(y), CODE:{[count(x), CODE:{
	[testJson = json.set("{}", "test0",test0,"test1",test1,"test2",test2,"test3",test3,"test4",test4,"test5",test5,"test6",test6,"test7",test7,"test8",test8,"test9",test9)]
}]}]
[h: cif.stopwatch.end()]<tr><td>
set json object classic
</td><td> : [r: cif.stopwatch.getTime()]s</td></tr>


[h:'<!-- Create method 3: set json object through strProp list -->']
[h: cif.stopwatch.start()]
[h,count(y), CODE:{[count(x), CODE:{
	[h: testJson = json.fromStrProp(strPropFromVars(theList,"UNSUFFIXED"))]
}]}]
[h: cif.stopwatch.end()]<tr><td>
set json object with strProp method </td><td> : [r: cif.stopwatch.getTime()]s</td></tr><br>


[h:'<!-- Create method 4: create strProp list of variables with designated function -->']
[h: cif.stopwatch.start()]
[h,count(y), CODE:{[count(x), CODE:{
	[h:testStrProp = strPropFromVars(theList,"UNSUFFIXED")]
}]}]
[h: cif.stopwatch.end()]<tr><td>
set strProp object classic </td><td> : [r: cif.stopwatch.getTime()]s</td></tr><br>


[h:'<!-- Create method 5: create strProp list of variables with strformat -->']
[h: cif.stopwatch.start()]
[h,count(y), CODE:{[count(x), CODE:{
	[h:testStrProp = strformat('test0=%{test0};test1=%{test1};test2=%{test2};test3=%{test3};test4=%{test4};test5=%{test5};test6=%{test6};test7=%{test7};test8=%{test8};test9=%{test9}')]
}]}]
[h: cif.stopwatch.end()]<tr><td>
set strProp object with strformat </td><td> : [r: cif.stopwatch.getTime()]s</td></tr><br>

[h:'<!------------------------------------ STORE --------------------------------------------->']
[h:'<!-- Save method 1: as json object -->']
[h: cif.stopwatch.start()]
[h,count(y), CODE:{[count(x), CODE:{
	[h:setLibProperty("testJson",testJson,"lib:OntokenMove")]
}]}]
[h: cif.stopwatch.end()]<tr><td>
save as json object </td><td> : [r: cif.stopwatch.getTime()]s</td></tr><br>

[h:'<!-- Save method 2: as strProp object -->']
[h: cif.stopwatch.start()]
[h,count(y), CODE:{[count(x), CODE:{
	[h:setLibProperty("testStrProp",testStrProp,"lib:OntokenMove")]
}]}]
[h: cif.stopwatch.end()]<tr><td>
save as strProp object </td><td> : [r: cif.stopwatch.getTime()]s</td></tr><br>

[h:'<!-- Save method 3: as seperate variables -->']
[h: cif.stopwatch.start()]
[h,count(y), CODE:{[count(x), CODE:{
	[h:setLibProperty("test0", test0,"lib:OntokenMove")]
	[h:setLibProperty("test1", test1,"lib:OntokenMove")]
	[h:setLibProperty("test2", test2,"lib:OntokenMove")]
	[h:setLibProperty("test3", test3,"lib:OntokenMove")]
	[h:setLibProperty("test4", test4,"lib:OntokenMove")]
	[h:setLibProperty("test5", test5,"lib:OntokenMove")]
	[h:setLibProperty("test6", test6,"lib:OntokenMove")]
	[h:setLibProperty("test7", test7,"lib:OntokenMove")]
	[h:setLibProperty("test8", test8,"lib:OntokenMove")]
	[h:setLibProperty("test9", test9,"lib:OntokenMove")]
}]}]
[h: cif.stopwatch.end()]<tr><td>
save as seperate variables </td><td> : [r: cif.stopwatch.getTime()]s</td></tr><br>

[h:'<!------------------------------------ RETRIEVE --------------------------------------------->']
[h:'<!-- Retrieve method 1: from json object -->']
[h: cif.stopwatch.start()]
[h,count(y), CODE:{[count(x), CODE:{
	[h:result = getLibProperty("testJson","lib:OntokenMove")]
	[h:varsFromStrProp(json.toStrProp(result))]
}]}]
[h: cif.stopwatch.end()]<tr><td>
Retrieve json object </td><td> : [r: cif.stopwatch.getTime()]s</td></tr><br>

[h:'<!-- Retrieve method 2: from strprop object -->']
[h: cif.stopwatch.start()]
[h,count(y), CODE:{[count(x), CODE:{
	[h:result = getLibProperty("testStrProp","lib:OntokenMove")]
	[h:varsFromStrProp(result)]
}]}]
[h: cif.stopwatch.end()]<tr><td>
Retrieve strProp object </td><td> : [r: cif.stopwatch.getTime()]s</td></tr><br>

[h:'<!-- Retrieve method 1: from seperate variables -->']
[h: cif.stopwatch.start()]
[h,count(y), CODE:{[count(x), CODE:{
	[h:test0 = getLibProperty("test0","lib:OntokenMove")]
	[h:test1 = getLibProperty("test1","lib:OntokenMove")]
	[h:test2 = getLibProperty("test2","lib:OntokenMove")]
	[h:test3 = getLibProperty("test3","lib:OntokenMove")]
	[h:test4 = getLibProperty("test4","lib:OntokenMove")]
	[h:test5 = getLibProperty("test5","lib:OntokenMove")]
	[h:test6 = getLibProperty("test6","lib:OntokenMove")]
	[h:test7 = getLibProperty("test7","lib:OntokenMove")]
	[h:test8 = getLibProperty("test8","lib:OntokenMove")]
	[h:test9 = getLibProperty("test9","lib:OntokenMove")]
}]}]
[h: cif.stopwatch.end()]<tr><td>
Retrieve seperate variables </td><td> : [r: cif.stopwatch.getTime()]s</td></tr><br>

</table>
[h: cif.stopwatch.end()]

benchmark result

10 cycles (y=1, x=10)
set json object with strformat: 0.222s
set json object classic: 0.070s
set json object with strProp method: 0.050s
set strProp object classic: 0.034s
set strProp object with strformat: 0.035s
save as json object: 1.138s
save as strProp object: 1.151s
save as seperate variables: 11.198s
Retrieve json object: 0.049s
Retrieve strProp object: 0.038s
Retrieve seperate variables: 0.150s

From this you can see that storing the var on a libToken takes the most time, so its advisable to combine as much variables into one variable and store and retrieve that one and then split it up again in seperate variables.
Also retrieving the vars, although much faster, is still a limiting factor as in this case its 3x slower.

After this I removed the slow parts (seperate variables and the store part) and ran a heavier test for the remaining code:

benchmark result remainder

10,000 cycles (y=10, x=1000)

set json object with strformat: 9.173s
set json object classic: 13.116s
set json object with strProp method: 9.617s
set strProp object classic: 9.086s
set strProp object with strformat: 9.196s
Retrieve json object: 14.679s
Retrieve strProp object: 13.728s

conclusion:
- Saving a var on a libToken is (relatively speaking) extremely slow, so storing each variable separately is inadvisable (assuming of course that you need the variables in one macro)
- creating a json object 'as you should' versus using a strformat trick [strformat('{"x":"%{x}"}')] --> strformat wins by a long shot. However I have problem reading the result of the strformat trick, so I'm doing something wrong.
- creating a strprop using strPropsFromVars vs using strformat is equally fast.
- saving a json object or a strProp to a libToken is equally fast
- retrieving and creating vars from a json object vs a strProp list --> strProp is slightly faster (which is not so strange as you need an extra call for the json object)
In short strProp method in this case is the fastest.

Do note ofcourse that json objects are much more versatile then strProps. So do NOT conclude from this that you should always use strProps, cause e.g. you can't nest strprops inside strprops (well actually you can but its messy) also the content that you can save in a json object is much more versatile then in a strProp.
The only thing I tried to learn from this exercise is which method can best be used to store and retrieve large amounts of 'simple' variables on a lib token.

[wolph42]

Done some more benchmarks, which rather amazed me:
Nested function

Code: Select all

[varsFromStrProp(json.toStrProp(json.fromStrProp(strPropFromVars(theList,"UNSUFFIXED")))] 

Unnested function

Code: Select all

[tmp = strPropFromVars(theList,"UNSUFFIXED")]
[testJson = json.fromStrProp(tmp)]
[tmp1  = json.toStrProp(testJson)]
[varsFromStrProp(tmp1)] 

It turned out that nested is more than twice as fast

Direct, versus UDF versus MACRO:

Code: Select all

1  [r:"Test"]
2 [r:Test()]
3  [r,macro("Test@lib:cifStopwatch"):""]
4 [r:eval("Test()")]
The function Test() contains the macro [r:"Test"] 

Running 10,000 times: (1) 8.5s, (2) 14.3s, (3) 18.5 and (4) 15.4 seconds.

You can read the rest in Speed Up Your Macros

[Azhrei]

It doesn't surprise me that the nested version is faster. When using variable names there will be a variable lookup that must occur. If you don't create separate scopes for your UDFs, looking up a variable becomes slower and slower as you have more of them. Now, the lookup is via a hash table so I wouldn't expect it to get slow right away...

Your earlier conclusions might be suspect. MTscript converts strings to JSON objects and back again based on the first non-whitespace character being a "{" or "[". It's possible that your benchmark code contains instances where a string is being converted into a JSON object or array, then being converted back when used as a string. Obviously there's some overhead with that. But I didn't look at your benchmark code line by line to see if that was occurring. Unfortunately, it's difficult for someone not familiar with the code to determine whether this is happening, since JSON objects are converted to strings on the fly as needed, which means the only way to know is to use Wiki: json.type() on it (I think that's the function). You could try adding that to snippets of your benchmark code to ensure the data types are changing behind the scenes.

[StarMan]

conclusion:
- Saving a var on a libToken is (relatively speaking) extremely slow, so storing each variable separately is inadvisable (assuming of course that you need the variables in one macro)

Doing so on a regular non-libToken is no picnic either. I had a macro which ran at a glacial pace when setProperty-ing a bunch of variables on a regular token. After amalgamating them all into a single SPL, the code is more readable and it now runs like a bat outta heck. I guess lotsa I/O (for want of a better term for "getting/setting") on the token was incurring overhead.

Yes JSON's are more versatile but I still avoid them like the proverbial plague. I can count on one hand the number of times I've used them in my framework. Their necessity even in those instances is debatable. Yes, I am guilty of piecing them together with long complicated concatenation coding (is that taking alliteration too far?) but that was before I learned of the strFormat method. No biggie as I only do this when performance is largely irrelevant.