Performance issue when combining userFormulas, grouping, and summaries

[senordhuff]

Hi guys,

We've been struggling with some performance problems for some of our users for a few months now. And, I'm finally making some headway into understanding the problem. I'm hoping you can provide some guidance. This is somewhat urgent because we've developed some frustrated users.

Here is the deal. These users have a list grid with the following

1. User defined hilites

2. About 10 user formulas...several formulas referring to other formulas

3. Grouping that typically results in 10-15 different groups

4. Grid summaries showing 3 summary rows and Group summaries also showing 3 summary rows for each group.

After debugging today, I realize the combination of all this functionality is the root of the problem. It seems when summary rows are recalculated, each unique summary row is causing the groupTreeChanged event to fire on the grid as a whole. And, each time the groupTreeChanged event fires, applylHilites is called every time. When applyHilites is called, every formula is recalculated. So, this appears to be a cascading chain of events that is causing significant slowness.

If we remove the grid and group summaries, the app speeds up significantly. If we reduce the number of summary rows on the grid and the group from 3 rows to 1, it also speeds up significantly. If we remove grouping, again it speeds up. If we change grouping so that it is only 1 or 2 groups instead of 10, again improvement. If we remove hilites, big improvement. But, the requirement for our users is to be able to combine all of these features into their grids.

So, it seems like the root of the problem is that the groupTreeChanged event is firing every time a summary row is updated. But, there may be other ways to improve this such as not re-calculating formulas every time we applyHilites if possible. I can send you a google chrome cpu profile showing what it looks like when CPU on a client machine has been pegged as a result of this problem if that is helpful.

Please let me know what you think. Hopefully that gives you enough detail to understand the issue. I started to try re-producing the setup above with one of your examples like this one: http://www.smartclient.com/#summaryGridFS but wasn't sure how to use that example to demonstrate the firing of groupTreeChanged over and over again.

[senordhuff]

Another note on this. We have showHilitesInGroupSummary:false on our grids. So, it seems especially inefficient in this case to have the groupTreeChanged event fire in response to an update to a summary row which then calls applyHilites since showHilitesInGroupSummary:false means that there will be no hilite updates as a result. It would be nice if there was some simple way to avoid the call to applyHilites if showHilitesInGroupSummary:false. Still doesn't seem to make sense to fire groupTreeChanges for each individual summary row. But, that could be a workaround for our problem if possible.

[Isomorphic]

Separately you contacted us saying that you were having trouble isolating this problem to a test case. Has that changed? Do you have a test case you can share that demonstrates that *just* these features in combination will replicate a performance issue?

[senordhuff]

No, the relevant test case is just a test case showing groupTreeChanged firing every time a single summary row is recalculated. And, I wasn't sure how to demonstrate that in one of your Feature Explorer examples. I think that is the starting point more than trying to replicate our performance issues because groupTreeChanged firing on the entire grid and then calling applyHilites on the entire grid is the root of the problem for us. Is there a way to avoid groupTreeChanged calling applyHilites on the entire grid when a summary row is recalculated? Another option possibly is to allow for applying hilites at a row level so that applyHilites is not called for the entire grid in response to an update to one summary row.

[Isomorphic]

Well, you seem to be saying that this disastrous series of calls arises from the use of a specific set of features. If so, then you should be able to straightforwardly combine those features and produce a test case that replicates the performance problem.

There isn't really another approach. Obviously we can't just make speculative changes to the product and ask you to tell us if something's faster, right?

[senordhuff]

There is no way to reproduce the specific performance problems we have in a test case for you. And, as you know, performance problems are somewhat subjective. I could try to produce something and then you might say that the performance seems acceptable to you, right?

However, I can definitively tie our performance problems to the firing of groupTreeChanged on the entire grid for each summary row. Does it help to provide a test case showing groupTreeChanged firing every time a summary row is updated? Or, do you have another recommendation on how we should move forward to resolve this issue for our users?

[Isomorphic]

There is no way to reproduce the specific performance problems we have in a test case for you.

That doesn't make much sense to us, particularly since you just asserted that a straightforward combination of features produces the problem.

Unfortunately, if this is really what you think, that would mean we have to close this as a Support ticket, because there is no way in which we can move forward. As we said, we cannot make speculative changes to the product in the hopes that it might improve the performance of your application.

So again, options are:

1. a test case that shows a performance problem that is a product flaw

OR

2. use Consulting hours so that you can have someone investigate your actual application code, without any concern about whether it's a product issue or not.

[senordhuff]

Well, the problem here is that I identified code in the framework that I believed to be inefficient and punitive for us as a result. I had low confidence that I could produce a test case for you that adequately displayed this inefficiency. For the record, we've done something very similar to this before off-list. In May 2012, you guys worked with us on identifying some inefficiencies in you server-side JSON serialization that were impacting us significantly (despite no reports from other customers) that ended up being a performance boost for the framework as a whole. So, this is not without precedent. But, enough verbal jousting for now. The good news is that I was able to in fact produce a performance problem in your Feature Explorer with a little effort.

Start with the #formulaHilites example. My local URL is http://localhost:8082/isomorphic/system/reference/SmartClient_Explorer.html#formulaHilites

Use the code below. It adds some counters to count the times that groupTreeChanged is fired, applyHilites is fired, and formulas are fired as well as the time it takes for recalculateSummaries to complete. The counters work because I put in overrides to applyHilites and getFormulaFieldValue and groupTreeChanged. These don't change framework code in any way. They are just there to allow me to update the counters.

Step 1. Press the Recalculate Summaries button. You'll see it completes in a respectable amount of time. For me in Google Chrome that is 156 millilseconds on average.

Step 2. Add a Formula Column with the name "Double Population" and the formula "doublePopulation(record)"; and click Save. Reset Counters > Reclaulcate Summaries. With this formula field now, you'll see that the execution time of recalculateSummaries jumps significantly to about 500 milliseconds on average. And, the formula counter shows the formula being fired 4000+ times for this one call to recalculate summaries.

Step 3. Add another Formula column with the name "Quadruple Population" and the formula <Double population column> * 2 (probably D*2) . Save > Reset Counters > Recalculate Summaries. Now, the time jumps to about 1300 milliseconds on average. That single call to recalculateSummaries ends up executing formulas over 13000 times.

Step 4. Try the same steps for 1-3 but change the summary functions from this countryList.fields.setProperty("summaryFunction", ['sum','avg','max']) to this:
countryList.fields.setProperty("summaryFunction", ['sum']) and you'll see the time decreased signficantly from 1300 milliseconds to about 800 milliseconds for step 3 proving that the additional summary rows are punitive.


So, is that a good enough test case to investigate this problem? If you add a larger grid with hundreds of records. And, you add 5-10 more formulas, this only gets worse. As mentioned, I believe the root of the problem is that each summary row is causing groupTreeChanged to fire which in turn causes applyHilites to fire on the entire grid. So, each additional summary row in the grid is punitive in this case. And, as mentioned, we've got some very frustrated users on our hands. And, hopefully this illustrates clearly why they are frustrated and we can get some sort of fix for this issue soon.

	isc.Canvas.getPrototype().addProperties({
		
		applyHilites : function (_1) {
			
			
              isc.applyHilitesCounter++;

		    var _2 = this.hilites,
		        _3 = this.data;
		    if (_2 && !this.$58b) this.$63j(_2, true);
		    if (isc.isA.ResultSet(_3)) _3 = _3.getAllLoadedRows();
		    if (isc.isA.Tree(_3)) _3 = _3.getAllItems();
		    _3.setProperty(this.hiliteMarker, null);
		    var _4 = this.getAllFields();
		    if (_4 == null) _4 = [];
		    var _5 = isc.addProperties({}, this.$120n),
		        _6 = isc.addProperties({}, this.$120o);
		    for (var j = 0; j < _3.length; j++) {
		        for (var i = 0; i < _4.length; i++) {
		            var _9 = _4[i],
		                _10 = _9[this.fieldIdProperty];
		            if (_9.userFormula || _9.userSummary) {
		                if (j == 0 && _9.userSummary && !_9.$652) {
		                    this.getSummaryFunction(_9)
		                }
		                if (_9.userFormula) {
		                	
		        			//isc.Log.logInfo("detail applyHilites for _9.name=" + _9.name);

		                    this.storeFormulaFieldValue(_3[j], _10, this.getFormulaFieldValue(_9, _3[j]));
		                    if (j == 0) {
		                        delete _6[_10]
		                    }
		                } else {
		                    this.storeSummaryFieldValue(_3[j], _10, _9.$652(_3[j], _10, this));
		                    if (j == 0) {
		                        delete _5[_9.name]
		                    }
		                }
		            }
		        }
		        for (var _11 in _5) {
		            delete _3[j][_11]
		        }
		        for (var _12 in _6) {
		            delete _3[j][_12]
		        }
		    }
		    for (var _11 in _5) {
		        delete this.$120n[_11]
		    }
		    for (var _12 in _6) {
		        delete this.$120o[_12]
		    }
		    if (_2 != null) {
		        for (var i = 0; i < _2.length; i++) {
		            this.applyHilite(_2[i], _3)
		        }
		    }
		    if (!_1) this.redrawHilites()
		},


		getFormulaFieldValue:function(_1,_2){
			
		    if (!isc.isAn.Object(_1)) _1 = this.getField(_1);
		    
			var formulaFunction=this.getFormulaFunction(_1);
			if(formulaFunction!=null && isA.Function(formulaFunction)){
				try{
					
                                    isc.formulaFiredCounter++

					//11/20/13
					//convert NaN or infinite values to null if not a string
					var returnValue = formulaFunction(_2,this);
					//isc.Log.logInfo("in getFormulaFieldValue and, 1 retunValue  is "  + returnValue + " and _1=" + _1.name);

					if(!isFinite(returnValue) && !isA.String(returnValue)){
						//isc.Log.logInfo(" 2 retunValue is not finite, value is "  + returnValue + " so setting to null ");
						returnValue=null;
					}
					return returnValue;
				}catch(e){
					//11/20/13..added exception handling
					//isc.Log.logInfo("exception calling formulaFunction in getFormulaFieldValue, _1=" + _1 + " ,  e:" + e)
					return null;
				}
			}else{
				//isc.Log.logInfo("couldn't resolve formula function for in getFormulaFieldValue, _1=" + _1 )
				return null;
			}
		}


})

isc.groupTreeChangedCounter=0;
isc.applyHilitesCounter=0;
isc.formulaFiredCounter=0;

isc.defineClass("ATListGrid", "ListGrid").addProperties({

        showGridSummary:true,
        showGroupSummary:true,
	    groupByAsyncThreshold: 1500,

	groupTreeChanged : function () {
		
              isc.groupTreeChangedCounter++
        	this.Super("groupTreeChanged", arguments);

    	}
})

var ds = isc.DataSource.get("countryDS");

isc.VLayout.create({
	ID:"layout",
	width:700, height:250,
	members: [
		isc.HLayout.create({
			ID:"buttonLayout",
			width:"*", height:30,
			membersMargin: 10,
			members: [
				isc.IButton.create({
				    ID: "recalculateSummariesButton",
				    autoFit: true,
				    title: "Recalculate Summaries",
				    click: "isc.groupTreeChangedCounter=0;displayCounters.setValue('groupTreeChangedCounter',isc.groupTreeChangedCounter);isc.applyHilitesCounter=0; displayCounters.setValue('applyHilitesCounter',isc.applyHilitesCounter);isc.formulaFiredCounter=0; displayCounters.setValue('formulaFiredCounter',isc.formulaFiredCounter);displayCounters.setValue('recalculateMillisecondsTimer',0);displayCounters.setValue('recalculateMillisecondsTimer',0);var timeStart=Date.now();countryList.recalculateSummaries();var timeStop=Date.now();displayCounters.setValue('recalculateMillisecondsTimer',timeStop - timeStart);displayCounters.setValue('groupTreeChangedCounter',isc.groupTreeChangedCounter);displayCounters.setValue('applyHilitesCounter',isc.applyHilitesCounter);displayCounters.setValue('formulaFiredCounter',isc.formulaFiredCounter);"
				}),
				isc.IButton.create({
				    ID: "resetCountersButton",
				    autoFit: true,
				    title: "Reset Counters",
				    click: "isc.groupTreeChangedCounter=0;displayCounters.setValue('groupTreeChangedCounter',isc.groupTreeChangedCounter);isc.applyHilitesCounter=0; displayCounters.setValue('applyHilitesCounter',isc.applyHilitesCounter);isc.formulaFiredCounter=0; displayCounters.setValue('formulaFiredCounter',isc.formulaFiredCounter);displayCounters.setValue('recalculateMillisecondsTimer',0);"
				}),
				isc.IButton.create({
				    ID: "formulaButton",
				    autoFit: true,
				    title: "Show Formula Builder",
				    click: "countryList.addFormulaField();"
				}),
				isc.IButton.create({
				    ID: "editHilitesButton",
				    autoFit: true,
				    title: "Edit Hilites",
				    click: "countryList.editHilites();"
				}),
				isc.IButton.create({
				    ID: "stateButton",
				    autoFit: true,
				    title: "Recreate from State",
				    click: function () {
				        var fieldState = countryList.getFieldState(true),
                            hiliteState = countryList.getHiliteState();

						countryList.destroy();
						recreateListGrid();
				        countryList.setFieldState(fieldState);
				        countryList.setHiliteState(hiliteState);
				    }
				})
			]
		}),
	isc.DynamicForm.create({
	    ID:"displayCounters",
	    padding:0,
	    numCols:1,
	    fields:[

	       		{name:"groupTreeChangedCounter",title:"Group Tree Changed Count", canEdit:false,colSpan:1,  type:"integer",shouldSaveValue:false},
	       		{name:"applyHilitesCounter",title:"Apply HIlites Count", canEdit:false,colSpan:1,  type:"integer",shouldSaveValue:false},
	       		{name:"formulaFiredCounter",title:"Formula Fired Count", canEdit:false,colSpan:1,  type:"integer",shouldSaveValue:false},
	       		{name:"recalculateMillisecondsTimer",title:"Recalculate Timer in Milliseconds", canEdit:false,colSpan:1,  type:"integer",shouldSaveValue:false}

	    			
	            ]
	            
	})
	]
});

recreateListGrid();

function recreateListGrid() {
	layout.addMember(isc.ATListGrid.create({
	    ID: "countryList",
	    width:"100%", height:"600",
	    alternateRecordStyles:true, cellHeight:22,
	    dataSource: ds,
    groupStartOpen:"all",
	    autoFetchData: true,
	    canAddFormulaFields: true,
	    canAddSummaryFields: true,
	    fields:[
	        {name:"countryCode", title:"Flag", width:50, type:"image", imageURLPrefix:"flags/16/", 
	            imageURLSuffix:".png"
	        },
	        {name:"countryName", title:"Country"},
	        {name:"capital", title:"Capital"},
	        {name:"population", title:"Population", formatCellValue:"isc.NumberUtil.toUSString(value)"},
	        {name:"area", title:"Area (km&sup2;)", formatCellValue:"isc.NumberUtil.toUSString(value)"},
	        {name:"gdp", formatCellValue:"isc.NumberUtil.toUSString(value)"}
	    ]
	}));


countryList.fields.setProperty("summaryFunction", ['sum','avg','max']);

       countryList.setHiliteState(([{
    "fieldName": "population",
    "criteria": {
        "fieldName": "population",
        "operator": "greaterThan",
        "value": 200000
    },
    "backgroundColor": "#99CC00",
    "cssText": "background-color:#99CC00;",
    "id": 16
}]));
       countryList.groupBy('countryName');

}



var doublePopulation={jsFunction:function(record){

             var returnValue = null;
              
            if(record!=null && record.population!=null){
              returnValue =  record.population * 2;

          }

		return returnValue;
	}
	,name:"doublePopulation",description:"doublePopulation"};
isc.MathFunction.registerFunction(doublePopulation);

[Isomorphic]

We've made a fix that reduces the number of formula evaluations by a factor of 20-30x for the sample you've provided. The fix should be in the next nightly builds of SC 9.1d/SGWT 4.1d and SC 9.0p/SGWT 4.0p.

We are considering further optimizations (to reduce the number even further) but there is no definite timeline at this point.

[senordhuff]

Thank you. That looks much improved. I noticed my sample went from 1300 ms to 60 ms. In our app, the difference went from 1800 ms to 600 ms. So, I'll have to investigate why our app didn't see the same level of improvement as the sample. I'd definitely be curious to hear more about your other optimizations. So, if you have any details you can share, please do. And, I'll let you know if I find anything else worth reporting after I investigate our app further. But, overall, big step in the right direction.

[senordhuff]

Hi, another question on this topic because I am reviewing our code and trying to determine if we are making extra unneeded calls to recalculateSummaries.

If you take the original sample I sent and add this line at the end, it appears that you must include the call to recalculateSummaries in order for the summary to update correctly. If you remove the call, then the population column updates but the summary does not. So, is it necessary to make the extra call to recalculateSummaries in this case? The reason I ask is because on a separate thread here http://forums.smartclient.com/showthread.php?t=25719&highlight=recalculateSummaries you guys said the following:

" recalculateSummaries should automatically be called, internally, in response to data change, meaning you don't have to call it explicitly.
If you actually have a case where you know the summaries need to be refreshed but it isn't happening automatically, you can call recalculateSummaries yourself to force that refresh."

So, should recalculateSummaries be firing automatically in response to that change? Or, do we need to make the explicit call?

isc.Timer.setTimeout("countryList.originalData.getRange(0,1)[0].population=100;countryList.markForRedraw();countryList.recalculateSummaries()", 2000);

[Isomorphic]

I'd definitely be curious to hear more about your other optimizations. So, if you have any details you can share, please do.

Other improvements would target chained formulae (as in your example) as well as hilighting of formula fields

[Isomorphic]

Because you're making a direct change to the record, recalculateSummaries would not be expected to fire automatically. Something like calling updateData() would cause automatic recalculation, but obviously this would be an attempt to save changes to the server, which is not what you want.