1 files changed, 381 insertions, 101 deletions

diff --git a/indra/newview/llfasttimerview.cpp b/indra/newview/llfasttimerview.cpp
index 92a3b9b2f5..35712163eb 100644
--- a/indra/newview/llfasttimerview.cpp
+++ b/indra/newview/llfasttimerview.cpp
@@ -32,7 +32,9 @@
 #include "llrect.h"
 #include "llerror.h"
 #include "llgl.h"
+#include "llimagepng.h"
 #include "llrender.h"
+#include "llrendertarget.h"
 #include "lllocalcliprect.h"
 #include "llmath.h"
 #include "llfontgl.h"
@@ -49,6 +51,8 @@
 #include "llfasttimer.h"
 #include "lltreeiterators.h"
 #include "llmetricperformancetester.h"
+#include "llviewerstats.h"
+
 //////////////////////////////////////////////////////////////////////////////
 
 static const S32 MAX_VISIBLE_HISTORY = 10;
@@ -1020,6 +1024,327 @@ F64 LLFastTimerView::getTime(const std::string& name)
 	return 0.0;
 }
 
+void saveChart(const std::string& label, const char* suffix, LLImageRaw* scratch)
+{
+	//read result back into raw image
+	glReadPixels(0, 0, 1024, 512, GL_RGB, GL_UNSIGNED_BYTE, scratch->getData());
+
+	//write results to disk
+	LLPointer<LLImagePNG> result = new LLImagePNG();
+	result->encode(scratch, 0.f);
+
+	std::string ext = result->getExtension();
+	std::string filename = llformat("%s_%s.%s", label.c_str(), suffix, ext.c_str());
+	
+	std::string out_file = gDirUtilp->getExpandedFilename(LL_PATH_LOGS, filename);
+	result->save(out_file);
+}
+
+//static
+void LLFastTimerView::exportCharts(const std::string& base, const std::string& target)
+{
+	//allocate render target for drawing charts 
+	LLRenderTarget buffer;
+	buffer.allocate(1024,512, GL_RGB, FALSE, FALSE);
+	
+
+	LLSD cur;
+
+	LLSD base_data;
+
+	{ //read base log into memory
+		S32 i = 0;
+		std::ifstream is(base.c_str());
+		while (!is.eof() && LLSDSerialize::fromXML(cur, is))
+		{
+			base_data[i++] = cur;
+		}
+		is.close();
+	}
+
+	LLSD cur_data;
+	std::set<std::string> chart_names;
+
+	{ //read current log into memory
+		S32 i = 0;
+		std::ifstream is(target.c_str());
+		while (!is.eof() && LLSDSerialize::fromXML(cur, is))
+		{
+			cur_data[i++] = cur;
+
+			for (LLSD::map_iterator iter = cur.beginMap(); iter != cur.endMap(); ++iter)
+			{
+				std::string label = iter->first;
+				chart_names.insert(label);
+			}
+		}
+		is.close();
+	}
+
+	//get time domain
+	LLSD::Real cur_total_time = 0.0;
+
+	for (U32 i = 0; i < cur_data.size(); ++i)
+	{
+		cur_total_time += cur_data[i]["Total"]["Time"].asReal();
+	}
+
+	LLSD::Real base_total_time = 0.0;
+	for (U32 i = 0; i < base_data.size(); ++i)
+	{
+		base_total_time += base_data[i]["Total"]["Time"].asReal();
+	}
+
+	//allocate raw scratch space
+	LLPointer<LLImageRaw> scratch = new LLImageRaw(1024, 512, 3);
+
+	gGL.pushMatrix();
+	glLoadIdentity();
+	glMatrixMode(GL_PROJECTION);
+	glLoadIdentity();
+	glOrtho(-0.05, 1.05, -0.05, 1.05, -1.0, 1.0);
+
+	//render charts
+	gGL.getTexUnit(0)->unbind(LLTexUnit::TT_TEXTURE);
+	
+	buffer.bindTarget();
+
+	for (std::set<std::string>::iterator iter = chart_names.begin(); iter != chart_names.end(); ++iter)
+	{
+		std::string label = *iter;
+	
+		LLSD::Real max_time = 0.0;
+		LLSD::Integer max_calls = 0;
+		LLSD::Real max_execution = 0.0;
+
+		std::vector<LLSD::Real> cur_execution;
+		std::vector<LLSD::Real> cur_times;
+		std::vector<LLSD::Integer> cur_calls;
+
+		std::vector<LLSD::Real> base_execution;
+		std::vector<LLSD::Real> base_times;
+		std::vector<LLSD::Integer> base_calls;
+
+		for (U32 i = 0; i < cur_data.size(); ++i)
+		{
+			LLSD::Real time = cur_data[i][label]["Time"].asReal();
+			LLSD::Integer calls = cur_data[i][label]["Calls"].asInteger();
+
+			LLSD::Real execution = 0.0;
+			if (calls > 0)
+			{
+				execution = time/calls;
+				cur_execution.push_back(execution);
+				cur_times.push_back(time);
+			}
+
+			cur_calls.push_back(calls);
+		}
+
+		for (U32 i = 0; i < base_data.size(); ++i)
+		{
+			LLSD::Real time = base_data[i][label]["Time"].asReal();
+			LLSD::Integer calls = base_data[i][label]["Calls"].asInteger();
+
+			LLSD::Real execution = 0.0;
+			if (calls > 0)
+			{
+				execution = time/calls;
+				base_execution.push_back(execution);
+				base_times.push_back(time);
+			}
+
+			base_calls.push_back(calls);
+		}
+
+		std::sort(base_calls.begin(), base_calls.end());
+		std::sort(base_times.begin(), base_times.end());
+		std::sort(base_execution.begin(), base_execution.end());
+
+		std::sort(cur_calls.begin(), cur_calls.end());
+		std::sort(cur_times.begin(), cur_times.end());
+		std::sort(cur_execution.begin(), cur_execution.end());
+
+		//remove outliers
+		const U32 OUTLIER_CUTOFF = 512;
+		if (base_times.size() > OUTLIER_CUTOFF)
+		{ 
+			ll_remove_outliers(base_times, 1.f);
+		}
+
+		if (base_execution.size() > OUTLIER_CUTOFF)
+		{ 
+			ll_remove_outliers(base_execution, 1.f);
+		}
+
+		if (cur_times.size() > OUTLIER_CUTOFF)
+		{ 
+			ll_remove_outliers(cur_times, 1.f);
+		}
+
+		if (cur_execution.size() > OUTLIER_CUTOFF)
+		{ 
+			ll_remove_outliers(cur_execution, 1.f);
+		}
+
+
+		max_time = llmax(base_times.empty() ? 0.0 : *base_times.rbegin(), cur_times.empty() ? 0.0 : *cur_times.rbegin());
+		max_calls = llmax(base_calls.empty() ? 0 : *base_calls.rbegin(), cur_calls.empty() ? 0 : *cur_calls.rbegin());
+		max_execution = llmax(base_execution.empty() ? 0.0 : *base_execution.rbegin(), cur_execution.empty() ? 0.0 : *cur_execution.rbegin());
+
+
+		LLVector3 last_p;
+
+		//====================================
+		// basic
+		//====================================
+		buffer.clear();
+
+		last_p.clear();
+
+		LLGLDisable cull(GL_CULL_FACE);
+
+		LLVector3 base_col(0, 0.7f, 0.f);
+		LLVector3 cur_col(1.f, 0.f, 0.f);
+
+		gGL.setSceneBlendType(LLRender::BT_ADD);
+
+		gGL.color3fv(base_col.mV);
+		for (U32 i = 0; i < base_times.size(); ++i)
+		{
+			gGL.begin(LLRender::TRIANGLE_STRIP);
+			gGL.vertex3fv(last_p.mV);
+			gGL.vertex3f(last_p.mV[0], 0.f, 0.f);
+			last_p.set((F32)i/(F32) base_times.size(), base_times[i]/max_time, 0.f);
+			gGL.vertex3fv(last_p.mV);
+			gGL.vertex3f(last_p.mV[0], 0.f, 0.f);
+			gGL.end();
+		}
+		
+		gGL.flush();
+
+		
+		last_p.clear();
+		{
+			LLGLEnable blend(GL_BLEND);
+						
+			gGL.color3fv(cur_col.mV);
+			for (U32 i = 0; i < cur_times.size(); ++i)
+			{
+				gGL.begin(LLRender::TRIANGLE_STRIP);
+				gGL.vertex3f(last_p.mV[0], 0.f, 0.f);
+				gGL.vertex3fv(last_p.mV);
+				last_p.set((F32) i / (F32) cur_times.size(), cur_times[i]/max_time, 0.f);
+				gGL.vertex3f(last_p.mV[0], 0.f, 0.f);
+				gGL.vertex3fv(last_p.mV);
+				gGL.end();
+			}
+			
+			gGL.flush();
+		}
+
+		saveChart(label, "time", scratch);
+		
+		//======================================
+		// calls
+		//======================================
+		buffer.clear();
+
+		last_p.clear();
+
+		gGL.color3fv(base_col.mV);
+		for (U32 i = 0; i < base_calls.size(); ++i)
+		{
+			gGL.begin(LLRender::TRIANGLE_STRIP);
+			gGL.vertex3fv(last_p.mV);
+			gGL.vertex3f(last_p.mV[0], 0.f, 0.f);
+			last_p.set((F32) i / (F32) base_calls.size(), (F32)base_calls[i]/max_calls, 0.f);
+			gGL.vertex3fv(last_p.mV);
+			gGL.vertex3f(last_p.mV[0], 0.f, 0.f);
+			gGL.end();
+		}
+		
+		gGL.flush();
+
+		{
+			LLGLEnable blend(GL_BLEND);
+			gGL.color3fv(cur_col.mV);
+			last_p.clear();
+
+			for (U32 i = 0; i < cur_calls.size(); ++i)
+			{
+				gGL.begin(LLRender::TRIANGLE_STRIP);
+				gGL.vertex3f(last_p.mV[0], 0.f, 0.f);
+				gGL.vertex3fv(last_p.mV);
+				last_p.set((F32) i / (F32) cur_calls.size(), (F32) cur_calls[i]/max_calls, 0.f);
+				gGL.vertex3f(last_p.mV[0], 0.f, 0.f);
+				gGL.vertex3fv(last_p.mV);
+				gGL.end();
+				
+			}
+			
+			gGL.flush();
+		}
+
+		saveChart(label, "calls", scratch);
+
+		//======================================
+		// execution
+		//======================================
+		buffer.clear();
+
+
+		gGL.color3fv(base_col.mV);
+		U32 count = 0;
+		U32 total_count = base_execution.size();
+
+		last_p.clear();
+
+		for (std::vector<LLSD::Real>::iterator iter = base_execution.begin(); iter != base_execution.end(); ++iter)
+		{
+			gGL.begin(LLRender::TRIANGLE_STRIP);
+			gGL.vertex3fv(last_p.mV);
+			gGL.vertex3f(last_p.mV[0], 0.f, 0.f);
+			last_p.set((F32)count/(F32)total_count, *iter/max_execution, 0.f);
+			gGL.vertex3fv(last_p.mV);
+			gGL.vertex3f(last_p.mV[0], 0.f, 0.f);
+			gGL.end();
+			count++;
+		}
+
+		last_p.clear();
+				
+		{
+			LLGLEnable blend(GL_BLEND);
+			gGL.color3fv(cur_col.mV);
+			count = 0;
+			total_count = cur_execution.size();
+
+			for (std::vector<LLSD::Real>::iterator iter = cur_execution.begin(); iter != cur_execution.end(); ++iter)
+			{
+				gGL.begin(LLRender::TRIANGLE_STRIP);
+				gGL.vertex3f(last_p.mV[0], 0.f, 0.f);
+				gGL.vertex3fv(last_p.mV);
+				last_p.set((F32)count/(F32)total_count, *iter/max_execution, 0.f);			
+				gGL.vertex3f(last_p.mV[0], 0.f, 0.f);
+				gGL.vertex3fv(last_p.mV);
+				gGL.end();
+				count++;
+			}
+
+			gGL.flush();
+		}
+
+		saveChart(label, "execution", scratch);
+	}
+
+	buffer.flush();
+
+	gGL.popMatrix();
+	glMatrixMode(GL_MODELVIEW);
+	gGL.popMatrix();
+}
+
 //static
 LLSD LLFastTimerView::analyzePerformanceLogDefault(std::istream& is)
 {
@@ -1030,6 +1355,10 @@ LLSD LLFastTimerView::analyzePerformanceLogDefault(std::istream& is)
 	LLSD::Real total_time = 0.0;
 	LLSD::Integer total_frames = 0;
 
+	typedef std::map<std::string,LLViewerStats::StatsAccumulator> stats_map_t;
+	stats_map_t time_stats;
+	stats_map_t sample_stats;
+
 	while (!is.eof() && LLSDSerialize::fromXML(cur, is))
 	{
 		for (LLSD::map_iterator iter = cur.beginMap(); iter != cur.endMap(); ++iter)
@@ -1046,35 +1375,31 @@ LLSD LLFastTimerView::analyzePerformanceLogDefault(std::istream& is)
 
 			if (time > 0.0)
 			{
-				ret[label]["TotalTime"] = ret[label]["TotalTime"].asReal() + time;
-				ret[label]["MaxTime"] = llmax(time, ret[label]["MaxTime"].asReal());
-
-				if (ret[label]["MinTime"].asReal() == 0)
-				{
-					ret[label]["MinTime"] = time;
-				}
-				else
-				{
-					ret[label]["MinTime"] = llmin(ret[label]["MinTime"].asReal(), time);
-				}
-				
 				LLSD::Integer samples = iter->second["Calls"].asInteger();
 
-				ret[label]["Samples"] = ret[label]["Samples"].asInteger() + samples;
-				ret[label]["MaxSamples"] = llmax(ret[label]["MaxSamples"].asInteger(), samples);
-
-				if (ret[label]["MinSamples"].asInteger() == 0)
-				{
-					ret[label]["MinSamples"] = samples;
-				}
-				else
-				{
-					ret[label]["MinSamples"] = llmin(ret[label]["MinSamples"].asInteger(), samples);
-				}
+				time_stats[label].push(time);
+				sample_stats[label].push(samples);
 			}
 		}
 		total_frames++;
 	}
+
+	for(stats_map_t::iterator it = time_stats.begin(); it != time_stats.end(); ++it)
+	{
+		std::string label = it->first;
+		ret[label]["TotalTime"] = time_stats[label].mSum;
+		ret[label]["MeanTime"] = time_stats[label].getMean();
+		ret[label]["MaxTime"] = time_stats[label].getMaxValue();
+		ret[label]["MinTime"] = time_stats[label].getMinValue();
+		ret[label]["StdDevTime"] = time_stats[label].getStdDev();
+		
+		ret[label]["Samples"] = sample_stats[label].mSum;
+		ret[label]["MaxSamples"] = sample_stats[label].getMaxValue();
+		ret[label]["MinSamples"] = sample_stats[label].getMinValue();
+		ret[label]["StdDevSamples"] = sample_stats[label].getStdDev();
+
+		ret[label]["Frames"] = (LLSD::Integer)time_stats[label].getCount();
+	}
 		
 	ret["SessionTime"] = total_time;
 	ret["FrameCount"] = total_frames;
@@ -1109,8 +1434,27 @@ void LLFastTimerView::doAnalysisDefault(std::string baseline, std::string target
 	std::ofstream os(output.c_str());
 
 	LLSD::Real session_time = current["SessionTime"].asReal();
-	
-	os << "Label, % Change, % of Session, Cur Min, Cur Max, Cur Mean, Cur Total, Cur Samples, Base Min, Base Max, Base Mean, Base Total, Base Samples\n"; 
+	os <<
+		"Label, "
+		"% Change, "
+		"% of Session, "
+		"Cur Min, "
+		"Cur Max, "
+		"Cur Mean/sample, "
+		"Cur Mean/frame, "
+		"Cur StdDev/frame, "
+		"Cur Total, "
+		"Cur Frames, "
+		"Cur Samples, "
+		"Base Min, "
+		"Base Max, "
+		"Base Mean/sample, "
+		"Base Mean/frame, "
+		"Base StdDev/frame, "
+		"Base Total, "
+		"Base Frames, "
+		"Base Samples\n"; 
+
 	for (LLSD::map_iterator iter = base.beginMap();  iter != base.endMap(); ++iter)
 	{
 		LLSD::String label = iter->first;
@@ -1122,63 +1466,41 @@ void LLFastTimerView::doAnalysisDefault(std::string baseline, std::string target
 			continue;
 		}	
 		LLSD::Real a = base[label]["TotalTime"].asReal() / base[label]["Samples"].asReal();
-		LLSD::Real b = current[label]["TotalTime"].asReal() / base[label]["Samples"].asReal();
+		LLSD::Real b = current[label]["TotalTime"].asReal() / current[label]["Samples"].asReal();
 			
 		LLSD::Real diff = b-a;
 
 		LLSD::Real perc = diff/a * 100;
 
-		os << llformat("%s, %.2f, %.4f, %.4f, %.4f, %.4f, %.4f, %d, %.4f, %.4f, %.4f, %.4f, %d\n",
+		os << llformat("%s, %.2f, %.4f, %.4f, %.4f, %.4f, %.4f, %.4f, %.4f, %d, %d, %.4f, %.4f, %.4f, %.4f, %.4f, %.4f, %d, %d\n",
 			label.c_str(), 
 			(F32) perc, 
 			(F32) (current[label]["TotalTime"].asReal()/session_time * 100.0), 
+
 			(F32) current[label]["MinTime"].asReal(), 
 			(F32) current[label]["MaxTime"].asReal(), 
 			(F32) b, 
+			(F32) current[label]["MeanTime"].asReal(), 
+			(F32) current[label]["StdDevTime"].asReal(),
 			(F32) current[label]["TotalTime"].asReal(), 
+			current[label]["Frames"].asInteger(),
 			current[label]["Samples"].asInteger(),
 			(F32) base[label]["MinTime"].asReal(), 
 			(F32) base[label]["MaxTime"].asReal(), 
 			(F32) a, 
+			(F32) base[label]["MeanTime"].asReal(), 
+			(F32) base[label]["StdDevTime"].asReal(),
 			(F32) base[label]["TotalTime"].asReal(), 
+			base[label]["Frames"].asInteger(),
 			base[label]["Samples"].asInteger());			
 	}
 
-	
+	exportCharts(baseline, target);
+
 	os.flush();
 	os.close();
 }
 
-//-------------------------
-//static
-LLSD LLFastTimerView::analyzeMetricPerformanceLog(std::istream& is)
-{
-	LLSD ret;
-	LLSD cur;
-
-	while (!is.eof() && LLSDSerialize::fromXML(cur, is))
-	{
-		for (LLSD::map_iterator iter = cur.beginMap(); iter != cur.endMap(); ++iter)
-		{
-			std::string label = iter->first;
-
-			LLMetricPerformanceTesterBasic* tester = LLMetricPerformanceTesterBasic::getTester(iter->second["Name"].asString()) ;
-			if(tester)
-			{
-				ret[label]["Name"] = iter->second["Name"] ;
-
-				S32 num_of_metrics = tester->getNumberOfMetrics() ;
-				for(S32 index = 0 ; index < num_of_metrics ; index++)
-				{
-					ret[label][ tester->getMetricName(index) ] = iter->second[ tester->getMetricName(index) ] ;
-				}
-			}
-		}
-	}
-		
-	return ret;
-}
-
 //static
 void LLFastTimerView::outputAllMetrics()
 {
@@ -1194,48 +1516,6 @@ void LLFastTimerView::outputAllMetrics()
 }
 
 //static
-void LLFastTimerView::doAnalysisMetrics(std::string baseline, std::string target, std::string output)
-{
-	if(!LLMetricPerformanceTesterBasic::hasMetricPerformanceTesters())
-	{
-		return ;
-	}
-
-	// Open baseline and current target, exit if one is inexistent
-	std::ifstream base_is(baseline.c_str());
-	std::ifstream target_is(target.c_str());
-	if (!base_is.is_open() || !target_is.is_open())
-	{
-		llwarns << "'-analyzeperformance' error : baseline or current target file inexistent" << llendl;
-		base_is.close();
-		target_is.close();
-		return;
-	}
-
-	//analyze baseline
-	LLSD base = analyzeMetricPerformanceLog(base_is);
-	base_is.close();
-
-	//analyze current
-	LLSD current = analyzeMetricPerformanceLog(target_is);
-	target_is.close();
-
-	//output comparision
-	std::ofstream os(output.c_str());
-	
-	os << "Label, Metric, Base(B), Target(T), Diff(T-B), Percentage(100*T/B)\n"; 
-	for(LLMetricPerformanceTesterBasic::name_tester_map_t::iterator iter = LLMetricPerformanceTesterBasic::sTesterMap.begin() ; 
-		iter != LLMetricPerformanceTesterBasic::sTesterMap.end() ; ++iter)
-	{
-		LLMetricPerformanceTesterBasic* tester = ((LLMetricPerformanceTesterBasic*)iter->second) ;	
-		tester->analyzePerformance(&os, &base, &current) ;
-	}
-	
-	os.flush();
-	os.close();
-}
-
-//static
 void LLFastTimerView::doAnalysis(std::string baseline, std::string target, std::string output)
 {
 	if(LLFastTimer::sLog)
@@ -1246,7 +1526,7 @@ void LLFastTimerView::doAnalysis(std::string baseline, std::string target, std::
 
 	if(LLFastTimer::sMetricLog)
 	{
-		doAnalysisMetrics(baseline, target, output) ;
+		LLMetricPerformanceTesterBasic::doAnalysisMetrics(baseline, target, output) ;
 		return ;
 	}
 }