--- a/graphicstest/graphicstestharness/src/tprofiler.cpp Thu Aug 19 11:11:18 2010 +0300
+++ b/graphicstest/graphicstestharness/src/tprofiler.cpp Tue Aug 31 16:31:06 2010 +0300
@@ -1,4 +1,4 @@
-// Copyright (c) 2008-2009 Nokia Corporation and/or its subsidiary(-ies).
+// Copyright (c) 2008-2010 Nokia Corporation and/or its subsidiary(-ies).
// All rights reserved.
// This component and the accompanying materials are made available
// under the terms of "Eclipse Public License v1.0"
@@ -20,6 +20,7 @@
*/
#include <test/TestExecuteStepBase.h>
+#include <e32math.h>
#include <hal.h>
#include "tprofiler.h"
@@ -35,6 +36,14 @@
#define PROFILER_INFO_PRINTF6(p1, p2, p3, p4, p5, p6) iTestStep.Logger().LogExtra(((TText8*)__FILE__), __LINE__, ESevrInfo, (p1), (p2), (p3), (p4), (p5), (p6))
#define PROFILER_INFO_PRINTF7(p1, p2, p3, p4, p5, p6, p7) iTestStep.Logger().LogExtra(((TText8*)__FILE__), __LINE__, ESevrInfo, (p1), (p2), (p3), (p4), (p5), (p6), (p7))
+#define PROFILER_WARN_PRINTF1(p1) iTestStep.Logger().LogExtra(((TText8*)__FILE__), __LINE__, ESevrWarn, (p1))
+#define PROFILER_WARN_PRINTF2(p1, p2) iTestStep.Logger().LogExtra(((TText8*)__FILE__), __LINE__, ESevrWarn, (p1), (p2))
+#define PROFILER_WARN_PRINTF3(p1, p2, p3) iTestStep.Logger().LogExtra(((TText8*)__FILE__), __LINE__, ESevrWarn, (p1), (p2), (p3))
+#define PROFILER_WARN_PRINTF4(p1, p2, p3, p4) iTestStep.Logger().LogExtra(((TText8*)__FILE__), __LINE__, ESevrWarn, (p1), (p2), (p3), (p4))
+#define PROFILER_WARN_PRINTF5(p1, p2, p3, p4, p5) iTestStep.Logger().LogExtra(((TText8*)__FILE__), __LINE__, ESevrWarn, (p1), (p2), (p3), (p4), (p5))
+#define PROFILER_WARN_PRINTF6(p1, p2, p3, p4, p5, p6) iTestStep.Logger().LogExtra(((TText8*)__FILE__), __LINE__, ESevrWarn, (p1), (p2), (p3), (p4), (p5), (p6))
+#define PROFILER_WARN_PRINTF7(p1, p2, p3, p4, p5, p6, p7) iTestStep.Logger().LogExtra(((TText8*)__FILE__), __LINE__, ESevrWarn, (p1), (p2), (p3), (p4), (p5), (p6), (p7))
+
#define PROFILER_ERR_PRINTF1(p1) iTestStep.Logger().LogExtra(((TText8*)__FILE__), __LINE__, ESevrErr, (p1))
#define PROFILER_ERR_PRINTF2(p1, p2) iTestStep.Logger().LogExtra(((TText8*)__FILE__), __LINE__, ESevrErr, (p1), (p2))
#define PROFILER_ERR_PRINTF3(p1, p2, p3) iTestStep.Logger().LogExtra(((TText8*)__FILE__), __LINE__, ESevrErr, (p1), (p2), (p3)) ;
@@ -52,6 +61,7 @@
EXPORT_C CTProfiler::~CTProfiler()
{
iResults.Reset();
+ iResultsTimingOrder.Reset();
}
EXPORT_C CTProfiler* CTProfiler::NewL(CTestStep& aTestStep)
@@ -97,7 +107,24 @@
iResultsInitalised = ETrue;
iDiff = 0;
iResults.Reset();
+ iSessionId = Math::Random();
+ if (iSessionId < 1000000)
+ {
+ /*
+ * The reason for bumping up low session id values is that it allows
+ * us to in the future to re-compact the session ids into a unique
+ * number range from zero to one million. Duplicate session id values
+ * generated on the same day can cause confusion but will be very rare.
+ */
+ iSessionId += 1000000;
+ }
+ /*
+ * The build system needs to know the session id because it maps it to
+ * the job ID it is running, so it can map test results to a particular
+ * build in question.
+ */
+ PROFILER_INFO_PRINTF2(_L("SQL_SESSION_ID=%u"), iSessionId);
StartTimer();
}
@@ -106,10 +133,29 @@
*/
EXPORT_C void CTProfiler::MarkResultSetL()
{
- iResults.InsertInUnsignedKeyOrderAllowRepeatsL((TUint32)StopTimer());
+ MarkResultSetAndSuspendL();
+ StartTimer();
+ }
+
+/**
+Records set current time. Unlike MarkResultSetL() the function doesn't
+restart the timer at the end. The following operations will not be
+included into benchmark mesuarment. To resume the profiling the user must
+start the timer.
+@see StartTimer()
+@see MarkResultSetL()
+Can be called multiple times so an average can be taken.
+*/
+EXPORT_C void CTProfiler::MarkResultSetAndSuspendL()
+ {
+ TUint32 res = StopTimer();
+ iResults.InsertInUnsignedKeyOrderAllowRepeatsL(res);
+ if(iStoreResultInTimingOrder)
+ {
+ iResultsTimingOrder.AppendL(res);
+ }
iDiff = 0;
PROFILER_TEST(iResultsInitalised);
- StartTimer();
}
/**
@@ -118,6 +164,7 @@
EXPORT_C void CTProfiler::FreeResultsMemory()
{
iResults.Reset();
+ iResultsTimingOrder.Reset();
}
/**
@@ -127,12 +174,14 @@
{
TInt64 total = 0;
if (iResults.Count() <= 50)
- PROFILER_ERR_PRINTF2(_L("Not enough results for trimming - need more than 50, but got %d"), iResults.Count());
+ {
+ PROFILER_WARN_PRINTF2(_L("Not enough results for trimming - need more than 50, but got %d"), iResults.Count());
+ }
if (iResults.Count() == 0) // If iResults is zero then do nothing
{
return 0;
}
- PROFILER_TEST(iResults.Count() > 50); //Ensure we have an ability to remove some results in trimming
+
TInt twentyPercentCount = iResults.Count()/5;
for (TInt count = twentyPercentCount; count < iResults.Count()-twentyPercentCount; count++)
{
@@ -149,7 +198,7 @@
/**
Finds the maximum time taken
*/
-TUint32 CTProfiler::TimeMax()
+EXPORT_C TUint32 CTProfiler::TimeMax()
{
if (iResults.Count() == 0)
{
@@ -167,7 +216,7 @@
/**
Finds the minimum time taken
*/
-TUint32 CTProfiler::TimeMin()
+EXPORT_C TUint32 CTProfiler::TimeMin()
{
if (iResults.Count() == 0)
{
@@ -195,9 +244,19 @@
EXPORT_C void CTProfiler::ResultsAnalysis(const TDesC& aTestName, TInt aRotation, TInt aSrcScreenMode, TInt aDstScreenMode, TInt aIters)
{
PROFILER_TEST(iResultsInitalised);
-
- PROFILER_INFO_PRINTF7(_L("TID: %S Rot: %i SrcMode: %i DestMode: %i Iters: %i TrimmedMean: %i us"), &aTestName, aRotation, aSrcScreenMode, aDstScreenMode, aIters, GetTrimedMean());
- PROFILER_INFO_PRINTF3(_L("Max: %i Min: %i "), TimeMax(), TimeMin());
+ TBuf<128> variation;
+ variation.Format(KVariation, aRotation, aSrcScreenMode, aDstScreenMode,aIters);
+ TBuf<128> variationMax;
+ variationMax.Format(KMaxTime, &variation);
+ TBuf<128> variationMin;
+ variationMin.Format(KMinTime, &variation);
+ TBuf<128> variationTrimmedMean;
+ variationTrimmedMean.Format(KTrimmedMean, &variation);
+
+ SqlInsert(&aTestName, &variationTrimmedMean, &KMicroSeconds, GetTrimedMean());
+ SqlInsert(&aTestName, &variationMax, &KMicroSeconds, TimeMax());
+ SqlInsert(&aTestName, &variationMin, &KMicroSeconds, TimeMin());
+
iResultsInitalised = EFalse;
}
@@ -215,10 +274,21 @@
EXPORT_C void CTProfiler::ResultsAnalysisPixelRate(const TDesC & aTestName, TInt aRotation, TInt aSrcScreenMode, TInt aDstScreenMode, TInt aIters, TInt aNumPixelsPerIteration)
{
PROFILER_TEST(iResultsInitalised);
+
TReal time = (TReal)iResults[0] / 1000000;
- TInt32 pixelRate = aNumPixelsPerIteration*aIters/time;
- PROFILER_INFO_PRINTF7(_L("TID: %S Rot: %i SrcMode: %i DestMode: %i Iters: %i TrimmedMean: %i pixels/second"), &aTestName, aRotation, aSrcScreenMode, aDstScreenMode, aIters, pixelRate);
- PROFILER_INFO_PRINTF3(_L("Max: %i Min: %i "), TimeMax(), TimeMin());
+ TInt32 pixelRate = aNumPixelsPerIteration * aIters / time;
+
+ TBuf<128> variation;
+ variation.Format(KVariationPPI, aRotation, aSrcScreenMode, aDstScreenMode, aIters, aNumPixelsPerIteration);
+ TBuf<128> variationMax;
+ variationMax.Format(KMaxTime, &variation);
+ TBuf<128> variationMin;
+ variationMin.Format(KMinTime, &variation);
+
+ SqlInsert(&aTestName, &variation, &KPixelsPerSecond, pixelRate);
+ SqlInsert(&aTestName, &variationMax, &KMicroSeconds, TimeMax());
+ SqlInsert(&aTestName, &variationMin, &KMicroSeconds, TimeMin());
+
iResultsInitalised = EFalse;
}
@@ -238,8 +308,18 @@
PROFILER_TEST(iResultsInitalised);
TReal time = (TReal)iResults[0] / 1000000;
TInt32 characterRate = aNumCharsPerIteration*aIters/time;
- PROFILER_INFO_PRINTF7(_L("TID: %S Rot: %i SrcMode: %i DestMode: %i Iters: %i TrimmedMean: %i characters/second"), &aTestName, aRotation, aSrcScreenMode, aDstScreenMode, aIters, characterRate);
- PROFILER_INFO_PRINTF3(_L("Max: %i Min: %i "), TimeMax(), TimeMin());
+
+ TBuf<128> variation;
+ variation.Format(KVariationCPI, aRotation, aSrcScreenMode, aDstScreenMode, aIters, aNumCharsPerIteration);
+ TBuf<128> variationMax;
+ variationMax.Format(KMaxTime, &variation);
+ TBuf<128> variationMin;
+ variationMin.Format(KMinTime, &variation);
+
+ SqlInsert(&aTestName, &variation, &KCharacterRate, characterRate);
+ SqlInsert(&aTestName, &variationMax, &KMicroSeconds, TimeMax());
+ SqlInsert(&aTestName, &variationMin, &KMicroSeconds, TimeMin());
+
iResultsInitalised = EFalse;
}
@@ -259,11 +339,54 @@
{
PROFILER_TEST(iResultsInitalised);
- PROFILER_INFO_PRINTF7(_L("TID: %S Rot: %i SrcMode: %i DestMode: %i Iters: %i TrimmedMean: %i us"), &aTestName, aRotation, aSrcScreenMode, aDstScreenMode, aIters, iResults[0]/aIters);
- PROFILER_INFO_PRINTF3(_L("Max: %i Min: %i "), TimeMax(), TimeMin());
+ TUint32 result = iResults[0]/aIters;
+
+ TBuf<128> variation;
+ variation.Format(KVariation, aRotation, aSrcScreenMode, aDstScreenMode,aIters);
+ TBuf<128> variationMax;
+ variationMax.Format(KMaxTime, &variation);
+ TBuf<128> variationMin;
+ variationMin.Format(KMinTime, &variation);
+
+ SqlInsert(&aTestName, &variation, &KMicroSeconds, result);
+ SqlInsert(&aTestName, &variationMax, &KMicroSeconds, TimeMax());
+ SqlInsert(&aTestName, &variationMin, &KMicroSeconds, TimeMin());
+
iResultsInitalised = EFalse;
}
-
+
+/**
+ * Generate an SQL insert statement into the logs, intended for subsequent
+ * extraction by a script to load into the database.
+ * Inserts data fields for
+ * (sessionid, testname, testattribute, testunits, testresultvalue).
+ * An example insertion:
+ * <code>
+ * SQL_UPLOAD_VERSION_0:insert into performance.testresultstable (sessionid, testname, testattribute, testunits, testresultvalue) values
+ * SQL_UPLOAD_VERSION_0:('1136416860', 'GRAPHICS-UI-BENCH-S60-0009', 'Rot_0_SrcMode_0_DestMode_0_Iters_25', 'pixels/second', '394159');
+ * </code>
+ *
+ * @param aTestName Column testname
+ * @param aTestAttribute Column testattribute
+ * @param aTestUnit Column testunits
+ * @param aTestResultValue Column testresultvalue
+ */
+EXPORT_C void CTProfiler::SqlInsert(const TDesC* aTestName, const TDesC* aTestAttribute, const TDesC* aTestUnit, TInt32 aTestResultValue)
+ {
+ TBuf<200>scratchPad;
+ /*
+ * There is a 256 character limit on logging output, and a 7 vararg limit
+ * on the macro we can use to issue printfs to the test framework. Each
+ * output line which has SQL in it needs to have a marker at the front so
+ * that a script can reliably extract the SQL statements. Hence we use
+ * the following incremental strategy of getting our SQL statements output
+ * into the logs.
+ */
+ scratchPad.Format(KSqlInsert);
+ PROFILER_INFO_PRINTF2(_L("%S"), &scratchPad);
+ scratchPad.Format(KSqlData, iSessionId, aTestName, aTestAttribute, aTestUnit, aTestResultValue);
+ PROFILER_INFO_PRINTF2(_L("%S"), &scratchPad);
+ }
/**
Reports analysis results for frame rates
@@ -282,8 +405,19 @@
TReal time = (TReal)iResults[0] / 1000000;
TInt32 pixelRate = aNumPixelsPerIteration * aIters / time;
TInt32 frameRate = aIters / time;
- PROFILER_INFO_PRINTF7(_L("TID: %S Rot: %i SrcMode: %i DestMode: %i Iters: %i TrimmedMean: %i pixels/second"), &aTestName, aRotation, aSrcScreenMode, aDstScreenMode, aIters, pixelRate);
- PROFILER_INFO_PRINTF4(_L("Max: %i Min: %i Framerate: %i frames/second"), TimeMax(), TimeMin(), frameRate);
+
+ TBuf<128> variation;
+ variation.Format(KVariation, aRotation, aSrcScreenMode, aDstScreenMode, aIters);
+ TBuf<128> variationMax;
+ variationMax.Format(KMaxTime, &variation);
+ TBuf<128> variationMin;
+ variationMin.Format(KMinTime, &variation);
+
+ SqlInsert(&aTestName, &variation, &KPixelsPerSecond, pixelRate);
+ SqlInsert(&aTestName, &variation, &KFrameRate, frameRate);
+ SqlInsert(&aTestName, &variationMax, &KMicroSeconds, TimeMax());
+ SqlInsert(&aTestName, &variationMin, &KMicroSeconds, TimeMin());
+
iResultsInitalised = EFalse;
}
@@ -304,8 +438,19 @@
TReal time = (TReal)iResults[0] / 1000000;
TInt32 pixelRate = aNumPixelsPerIteration * aIters / time;
TInt32 frameRate = aIters / time;
- PROFILER_INFO_PRINTF7(_L("TID: %S Rot: %i SrcMode: %i DestMode: %i Iters: %i TrimmedMean: %i pixels/second"), &aTestName, aRotation, aSrcScreenMode, aDstScreenMode, aIters, pixelRate);
- PROFILER_INFO_PRINTF4(_L("Max: %i Min: %i Framerate: %i frames/second"), TimeMax(), TimeMin(), frameRate);
+
+ TBuf<128> variation;
+ variation.Format(KVariationPPI, aRotation, aSrcScreenMode, aDstScreenMode, aIters, aNumPixelsPerIteration);
+ TBuf<128> variationMax;
+ variationMax.Format(KMaxTime, &variation);
+ TBuf<128> variationMin;
+ variationMin.Format(KMinTime, &variation);
+
+ SqlInsert(&aTestName, &variation, &KPixelsPerSecond, pixelRate);
+ SqlInsert(&aTestName, &variation, &KFrameRate, frameRate);
+ SqlInsert(&aTestName, &variationMax, &KMicroSeconds, TimeMax());
+ SqlInsert(&aTestName, &variationMin, &KMicroSeconds, TimeMin());
+
iResultsInitalised = EFalse;
}
@@ -325,8 +470,19 @@
TReal time = (TReal)iResults[0] / 1000000;
TInt32 pixelRate = aNumPixelsPerIteration * aIters / time;
TInt32 frameRate = aIters / time;
- PROFILER_INFO_PRINTF7(_L("TID: %S Rot: %i SrcMode: %i DestMode: %i Iters: %i TrimmedMean: %i pixels/second"), &aTestName, aZorderSwitching, aSrcScreenMode, aDstScreenMode, aIters, pixelRate);
- PROFILER_INFO_PRINTF4(_L("Max: %i Min: %i Framerate: %i frames/second"), TimeMax(), TimeMin(), frameRate);
+
+ TBuf<128> variation;
+ variation.Format(KVariationZOrder, aZorderSwitching, aSrcScreenMode, aDstScreenMode, aIters, aNumPixelsPerIteration);
+ TBuf<128> variationMax;
+ variationMax.Format(KMaxTime, &variation);
+ TBuf<128> variationMin;
+ variationMin.Format(KMinTime, &variation);
+
+ SqlInsert(&aTestName, &variation, &KPixelsPerSecond, pixelRate);
+ SqlInsert(&aTestName, &variation, &KFrameRate, frameRate);
+ SqlInsert(&aTestName, &variationMax, &KMicroSeconds, TimeMax());
+ SqlInsert(&aTestName, &variationMin, &KMicroSeconds, TimeMin());
+
iResultsInitalised = EFalse;
}
@@ -358,8 +514,70 @@
EXPORT_C void CTProfiler::ResultsAnalysisAverageByNumberOfIterations(const TDesC& aTestName, TInt aRotation, TInt aSrcScreenMode, TInt aDstScreenMode,TInt aIters)
{
PROFILER_TEST(iResultsInitalised);
+ TBuf<128> variation;
+ variation.Format(KVariation, aRotation, aSrcScreenMode, aDstScreenMode, aIters);
+ TBuf<128> variationMean;
+ variationMean.Format(KMean, &variation);
+ TBuf<128> variationMax;
+ variationMax.Format(KMaxTime, &variation);
+ TBuf<128> variationMin;
+ variationMin.Format(KMinTime, &variation);
+
+ SqlInsert(&aTestName, &variationMean, &KMicroSeconds, Mean());
+ SqlInsert(&aTestName, &variationMax, &KMicroSeconds, TimeMax());
+ SqlInsert(&aTestName, &variationMin, &KMicroSeconds, TimeMin());
- PROFILER_INFO_PRINTF7(_L("TID: %S Rot: %i SrcMode: %i DestMode: %i Iters: %i TrimmedMean: %i us"), &aTestName, aRotation, aSrcScreenMode, aDstScreenMode, aIters, Mean());
- PROFILER_INFO_PRINTF3(_L("Max: %i Min: %i "), TimeMax(), TimeMin());
iResultsInitalised = EFalse;
}
+
+/**
+Output all results.
+*/
+EXPORT_C void CTProfiler::ShowResultArrayInTimingOrder()
+ {
+ for(TInt i=0; i < iResultsTimingOrder.Count(); i++)
+ {
+ PROFILER_INFO_PRINTF3(_L("iResultsTimingOrder[%4d]: %8d"),i, iResultsTimingOrder[i]);
+ }
+ }
+
+/**
+ @param aStoreResultInTimingOrder Signify whether the results should be stored as they coming
+ */
+EXPORT_C void CTProfiler::SetStoreResultInTimingOrder(TBool aStoreResultInTimingOrder)
+ {
+ iStoreResultInTimingOrder = aStoreResultInTimingOrder;
+ }
+
+/**
+Reports analysis results for glyph rates
+
+@param aTestName is the name of the test case
+@param aRotation is the screen rotation being used in the test
+@param aSrcScreenMode is the source screen mode being used,
+i.e. for bitmap display conversion the source and destinations bitmaps maybe different
+@param aDstScreenMode is the destination screen mode (usually the display screen mode)
+@param aIters is the number of iterations used in the test
+@param aNumGlyphs is the number of glyphs used per iteration
+*/
+
+EXPORT_C void CTProfiler::ResultsAnalysisGlyphRate(const TDesC & aTestName, TInt aRotation, TInt aSrcScreenMode, TInt aDstScreenMode, TInt aIters, TInt aNumGlyphsPerIteration)
+ {
+ PROFILER_TEST(iResultsInitalised);
+ TReal time = (iResults.Count() > 0) ? (TReal)iResults[0] / 1000000 : 0;
+ TInt32 glyphRate = aNumGlyphsPerIteration*aIters/time;
+
+ TBuf<128> variation;
+ variation.Format(KVariationCPI, aRotation, aSrcScreenMode, aDstScreenMode, aIters, aNumGlyphsPerIteration);
+ TBuf<128> variationMax;
+ variationMax.Format(KMaxTime, &variation);
+ TBuf<128> variationMin;
+ variationMin.Format(KMinTime, &variation);
+
+ SqlInsert(&aTestName, &variation, &KGlyphRate, glyphRate);
+ SqlInsert(&aTestName, &variationMax, &KMicroSeconds, TimeMax());
+ SqlInsert(&aTestName, &variationMin, &KMicroSeconds, TimeMin());
+
+ iResultsInitalised = EFalse;
+ }
+