Board index FlightGear Development Nasal

getprop() and performance

Nasal is the scripting language of FlightGear.

getprop() and performance

Postby Philosopher » Thu Feb 20, 2014 5:41 pm

Hey, time for Nasal and props discussions again ;).

My recent merge request was merged yesterday in this commit: 34ed79e5f88ffdfc5e651a1fe3e639cb8f4d3353. Basically removes nearly all needs for concatenation in setprop()/getprop(), except for odd cases like (control~"-norm"), where the concatenation is in the middle of a path part. Anyways, I started on a simple profiling script, basically testing performance of props.Node versus getprop() and concatenation versus no concatenation versus implicit concatenation (what my patch extended to cover indexes). Currently I haven't tested indexing concatenation, but just a simple path (/sim/current-view/config/default-field-of-view-deg) with concatenation at each slash.

Here's the script:
Code: Select all
var value = getprop("/sim/current-view/config/default-field-of-view-deg");
if (value == nil) die("uninitialized default field of view!");

var failed = {}; # keep track of which algorithms failed
var assert = func(a,name) { # verify results are correct
    if (a != value) {
        if (!contains(failed, name)) {
            failed[name]=1;
            print(name~" failed! a was "~debug.string(a));
        } else failed[name]+=1;
        return a;
    } else return a;
};
# list of all algorithms
var all_algo = {
    "algo PROPS.NODE SIMPLE":               func props.globals.getNode("/sim/current-view/config/default-field-of-view-deg").getValue(),
    "algo PROPS.NODE CHAINED 1":            func props.globals.getNode("/sim").getNode("current-view/config/default-field-of-view-deg").getValue(),
    "algo PROPS.NODE CHAINED 2":            func props.globals.getNode("/sim").getNode("current-view").getNode("config/default-field-of-view-deg").getValue(),
    "algo PROPS.NODE CHAINED 3":            func props.globals.getNode("/sim").getNode("current-view").getNode("config").getNode("default-field-of-view-deg").getValue(),
    "algo PROPS.NODE CHAINED 1 CONCAT 1":   func props.globals.getNode("/sim").getNode("current-view"~"/config/default-field-of-view-deg").getValue(),
    "algo PROPS.NODE CHAINED 2 CONCAT 1":   func props.globals.getNode("/sim").getNode("current-view").getNode("config"~"/default-field-of-view-deg").getValue(),
    "algo PROPS.NODE CHAINED 1 CONCAT 2":   func props.globals.getNode("/sim").getNode("current-view"~"/config"~"/default-field-of-view-deg").getValue(),
    "algo GETPROP SIMPLE":                  func getprop("/sim/current-view/config/default-field-of-view-deg"),
    "algo GETPROP CONCAT 1":                func getprop("/sim/current-view/config"~"/default-field-of-view-deg"),
    "algo GETPROP CONCAT 2":                func getprop("/sim/current-view"~"/config"~"/default-field-of-view-deg"),
    "algo GETPROP CONCAT 3":                func getprop("/sim"~"/current-view"~"/config"~"/default-field-of-view-deg"),
    "algo GETPROP NOCAT 1":                 func getprop("/sim/current-view/config","default-field-of-view-deg"),
    "algo GETPROP NOCAT 2":                 func getprop("/sim/current-view","config","default-field-of-view-deg"),
    "algo GETPROP NOCAT 3":                 func getprop("/sim","current-view","config","default-field-of-view-deg"),
    "algo GETPROP NOCAT 1 CONCAT 1":        func getprop("/sim/current-view"~"/config","default-field-of-view-deg"),
    "algo GETPROP NOCAT 1 CONCAT 2":        func getprop("/sim"~"/current-view"~"/config","default-field-of-view-deg"),
    "algo GETPROP NOCAT 2 CONCAT 1":        func getprop("/sim"~"/current-view","config","default-field-of-view-deg"),
};
# attach verification
foreach (var k; keys(all_algo)) {
    all_algo[k] = (func {
        var fn = all_algo[k];
        return func assert(fn(),k)
    })();
}
# sort into two categories: PROPS.NODE and GETPROP
var getprop_algo = {};
foreach (var k; keys(all_algo)) {
    if (find("GETPROP", k) != -1)
        getprop_algo[k] = all_algo[k];
}
var node_algo = {};
foreach (var k; keys(all_algo)) {
    if (find("PROPS.NODE", k) != -1)
        node_algo[k] = all_algo[k];
}

# test each and report to console
var repeat = 10000;
print("Testing each function "~repeat~" times");
debug.print_rank("getprop and props.Node", debug.rank(values(all_algo),     repeat), all_algo);
debug.print_rank("getprop",                debug.rank(values(getprop_algo), repeat), getprop_algo);
debug.print_rank("props.Node",             debug.rank(values(node_algo),    repeat), node_algo);

# and report which ones failed
if (size(failed)) {
    print("These algorithms failed X times:");
    debug.dump(failed);
}


Here's a sample result:
Code: Select all
Testing each function 10000 times
Test results for getprop and props.Node
  algo GETPROP SIMPLE (fastest) took 33.71500968933105 ms (13.93274966156102%) time
  algo GETPROP NOCAT 1 took 34.59000587463379 ms (14.29434240369514%) time
  algo GETPROP NOCAT 1 CONCAT 1 took 35.95495223999023 ms (14.85840737609783%) time
  algo GETPROP NOCAT 2 CONCAT 1 took 35.96115112304688 ms (14.86096906854892%) time
  algo GETPROP NOCAT 2 took 40.85922241210938 ms (16.88510021143815%) time
  algo GETPROP NOCAT 3 took 42.90986061096191 ms (17.73252777958409%) time
  algo GETPROP CONCAT 2 took 43.47705841064453 ms (17.96692263885851%) time
  algo GETPROP CONCAT 3 took 46.70810699462891 ms (19.30215556567095%) time
  algo GETPROP CONCAT 1 took 47.10316658020019 ms (19.46541419611135%) time
  algo GETPROP NOCAT 1 CONCAT 2 took 47.85299301147461 ms (19.77528045606008%) time
  algo PROPS.NODE SIMPLE took 118.9010143280029 ms (49.13592143092199%) time
  algo PROPS.NODE CHAINED 1 took 147.1869945526123 ms (60.82512113849495%) time
  algo PROPS.NODE CHAINED 1 CONCAT 1 took 155.0090312957764 ms (64.05758290523511%) time
  algo PROPS.NODE CHAINED 1 CONCAT 2 took 167.5639152526855 ms (69.24589685837978%) time
  algo PROPS.NODE CHAINED 2 took 203.1729221343994 ms (83.96134209038046%) time
  algo PROPS.NODE CHAINED 2 CONCAT 1 took 206.6459655761719 ms (85.396579549418%) time
  algo PROPS.NODE CHAINED 3 took 241.9838905334473 ms (100%) time
Test results for getprop
  algo GETPROP NOCAT 1 (fastest) took 33.5390567779541 ms (75.24350519103324%) time
  algo GETPROP NOCAT 2 took 34.75880622863769 ms (77.9799633070706%) time
  algo GETPROP SIMPLE took 34.96193885803223 ms (78.43568307150842%) time
  algo GETPROP NOCAT 3 took 35.77017784118652 ms (80.24893424691239%) time
  algo GETPROP NOCAT 1 CONCAT 2 took 38.60902786254883 ms (86.6177784196366%) time
  algo GETPROP NOCAT 2 CONCAT 1 took 42.30809211730957 ms (94.91647812063736%) time
  algo GETPROP NOCAT 1 CONCAT 1 took 43.71309280395508 ms (98.06853982466556%) time
  algo GETPROP CONCAT 2 took 43.72310638427734 ms (98.09100488347587%) time
  algo GETPROP CONCAT 1 took 44.47007179260254 ms (99.76679129425483%) time
  algo GETPROP CONCAT 3 took 44.57402229309082 ms (100%) time
Test results for props.Node
  algo PROPS.NODE SIMPLE (fastest) took 100.3341674804688 ms (44.84110747408619%) time
  algo PROPS.NODE CHAINED 1 took 139.9960517883301 ms (62.56670246863067%) time
  algo PROPS.NODE CHAINED 1 CONCAT 1 took 143.967866897583 ms (64.34177662984179%) time
  algo PROPS.NODE CHAINED 1 CONCAT 2 took 149.3179798126221 ms (66.73283636797601%) time
  algo PROPS.NODE CHAINED 2 CONCAT 1 took 193.6130523681641 ms (86.5290848336061%) time
  algo PROPS.NODE CHAINED 2 took 196.9478130340576 ms (88.01944813829788%) time
  algo PROPS.NODE CHAINED 3 took 223.7548828125 ms (100%) time


Make what conclusions you may - but props.Node is pretty bad, and passing separate arguments to getprop() is as good (if not better) than passing one argument (without concatenating it, i.e. scalar constant) :).

P.S. Forgot that I made changes to debug.nas for this - I'll push them to master soon so that the script works ;).
Thanks,
Philosopher
(inactive but lurking occasionally...)
Philosopher
 
Posts: 1590
Joined: Sun Aug 12, 2012 6:29 pm
Location: Stuck in my head...
Callsign: AFTI
Version: Git
OS: Mac OS X 10.7.5

Re: getprop() and performance

Postby Hooray » Thu Feb 20, 2014 5:54 pm

I think we've been tossing with the idea of using Tom's cppbind framework to update/modernize the props.nas/props.cxx stuff - and it would obviously also help with Canvas related stuff where lots of property tree I/O is a factor (i.e. taxiways layer) - so given that 3.0 is now out, this could be a good opportunity to re-implement props.nas on top of cppbind - indeed, it would be interest to benchmark a test case first - in theory - once implemented in native code, a cached property.setValue() call should be faster than plain setprop("foo", value). But to be honest, I haven't checked if Canvas already uses custom "native" setters/getters whenever we invoke .set/.get ...

PS: You should have really used fgplot to plot a graph of the results !! :lol:
Please don't send support requests by PM, instead post your questions on the forum so that all users can contribute and benefit
Thanks & all the best,
Hooray
Help write next month's newsletter !
pui2canvas | MapStructure | Canvas Development | Programming resources
Hooray
 
Posts: 11317
Joined: Tue Mar 25, 2008 8:40 am


Return to Nasal

Who is online

Users browsing this forum: No registered users and 1 guest