diff -r bbf46f59e123 -r 25ffed67c7ef graphicstest/graphicstestharness/src/tprofiler.cpp --- a/graphicstest/graphicstestharness/src/tprofiler.cpp Tue Aug 31 16:31:06 2010 +0300 +++ b/graphicstest/graphicstestharness/src/tprofiler.cpp Wed Sep 01 12:39:21 2010 +0100 @@ -1,4 +1,4 @@ -// Copyright (c) 2008-2010 Nokia Corporation and/or its subsidiary(-ies). +// Copyright (c) 2008-2009 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,7 +20,6 @@ */ #include -#include #include #include "tprofiler.h" @@ -36,14 +35,6 @@ #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)) ; @@ -61,7 +52,6 @@ EXPORT_C CTProfiler::~CTProfiler() { iResults.Reset(); - iResultsTimingOrder.Reset(); } EXPORT_C CTProfiler* CTProfiler::NewL(CTestStep& aTestStep) @@ -107,24 +97,7 @@ 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(); } @@ -133,29 +106,10 @@ */ EXPORT_C void CTProfiler::MarkResultSetL() { - 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); - } + iResults.InsertInUnsignedKeyOrderAllowRepeatsL((TUint32)StopTimer()); iDiff = 0; PROFILER_TEST(iResultsInitalised); + StartTimer(); } /** @@ -164,7 +118,6 @@ EXPORT_C void CTProfiler::FreeResultsMemory() { iResults.Reset(); - iResultsTimingOrder.Reset(); } /** @@ -174,14 +127,12 @@ { TInt64 total = 0; if (iResults.Count() <= 50) - { - PROFILER_WARN_PRINTF2(_L("Not enough results for trimming - need more than 50, but got %d"), iResults.Count()); - } + PROFILER_ERR_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++) { @@ -198,7 +149,7 @@ /** Finds the maximum time taken */ -EXPORT_C TUint32 CTProfiler::TimeMax() +TUint32 CTProfiler::TimeMax() { if (iResults.Count() == 0) { @@ -216,7 +167,7 @@ /** Finds the minimum time taken */ -EXPORT_C TUint32 CTProfiler::TimeMin() +TUint32 CTProfiler::TimeMin() { if (iResults.Count() == 0) { @@ -244,19 +195,9 @@ EXPORT_C void CTProfiler::ResultsAnalysis(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> 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()); - + + 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()); iResultsInitalised = EFalse; } @@ -274,21 +215,10 @@ 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; - - 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()); - + 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()); iResultsInitalised = EFalse; } @@ -308,18 +238,8 @@ PROFILER_TEST(iResultsInitalised); TReal time = (TReal)iResults[0] / 1000000; TInt32 characterRate = aNumCharsPerIteration*aIters/time; - - 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()); - + 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()); iResultsInitalised = EFalse; } @@ -339,54 +259,11 @@ { PROFILER_TEST(iResultsInitalised); - 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()); - + 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()); 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: - * - * 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'); - * - * - * @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 @@ -405,19 +282,8 @@ TReal time = (TReal)iResults[0] / 1000000; TInt32 pixelRate = aNumPixelsPerIteration * aIters / time; TInt32 frameRate = aIters / time; - - 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()); - + 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); iResultsInitalised = EFalse; } @@ -438,19 +304,8 @@ TReal time = (TReal)iResults[0] / 1000000; TInt32 pixelRate = aNumPixelsPerIteration * aIters / time; TInt32 frameRate = 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, &variation, &KFrameRate, frameRate); - 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 pixels/second"), &aTestName, aRotation, aSrcScreenMode, aDstScreenMode, aIters, pixelRate); + PROFILER_INFO_PRINTF4(_L("Max: %i Min: %i Framerate: %i frames/second"), TimeMax(), TimeMin(), frameRate); iResultsInitalised = EFalse; } @@ -470,19 +325,8 @@ TReal time = (TReal)iResults[0] / 1000000; TInt32 pixelRate = aNumPixelsPerIteration * aIters / time; TInt32 frameRate = aIters / time; - - 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()); - + 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); iResultsInitalised = EFalse; } @@ -514,70 +358,8 @@ 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; - } -