Symbian OS Profiling Sample Code:



In the header file for the app:

#ifdef TRACE
#define __APA_PROFILE_START(aNum) RDebug::ProfileStart(aNum)
#define __APA_PROFILE_END(aNum) RDebug::ProfileEnd(aNum)
#else
#define __APA_PROFILE_START(aNum)
#define __APA_PROFILE_END(aNum)
#endif





A typical profiled function:

TInt Class::Function( Parameters )
	{
	__APA_PROFILE_START(17);
	// The processing goes here...
	__APA_PROFILE_END(17);
	return 1;
	}





In the test application that does the profiling:

LOCAL_D RTest test(_L("Profile"));

	LOCAL_D DoProfiling();

	// Various initialisation stuff omitted here...

	/* 
	Important to keep a note of the profiling points (bins) used:
	0  - Process::AddNewDocument()
	1  - Process::OpenNewDocument()
	2  - Process::AddAppDllL()
	3  - Door::ConstructL()
	4  - Door::StoreL()
	5  - Door::Restore()
	6  - Door::SetFormatToIcon()
	7  - Door::SetFormatToGlass()
	8  - Door::SFTI::FindAIF
	9  - Door::Construct::OpenAIF
	10 - Door::GetDefaultIcon
	11 - Door::SFTI::CreateIcon
	12 - Door::ReadStreamDictionary
	13 - Door::Restore::InternalizeStreams
	14 - Door::Restore::InternalizeStore
	15 - Door::SFTI::FindApp
	16 - AppList::Update
	17 - AppData::UpdateAif
	*/

	RDebug::ProfileReset(0,21); // Resets profile bins between 0 and 20 (others left random)
	                            // There are KMaxProfiles (64) bins
	//
	// 
	test.Next(_L("Embedding 100 documents"));
	for (TInt i=0 ; i<100 ; i++)
		{
		RDebug::ProfileStart(20);
		((CTestAppDoc*)TheProcess->MainDocument())->EmbedNewDocL(dllname);
		RDebug::ProfileEnd(20);
		}
	//
	// get the results
	// This code does it one bin at a time, but you could get the whole lot as:
	// TProfile result[20];   RDebug::ProfileResult( &result, 0, 20 );

	TProfile result; // iTime, iCount
	TBuf<64> resultBuf;
	//
	RDebug::ProfileResult(&result,20,1);
	resultBuf.Format(_L("Embedding a doc - Time: %D, Count: %D"),result.iTime,result.iCount);
	test.Next(resultBuf);
	//
	RDebug::ProfileResult(&result,0,1);
	resultBuf.Format(_L("Process::AddNewDocument() - Time: %D, Count: %D"),result.iTime,result.iCount);
	test.Next(resultBuf);
	//
	RDebug::ProfileResult(&result,3,1);
	resultBuf.Format(_L("Door::Construct() - Time: %D, Count: %D"),result.iTime,result.iCount);
	test.Next(resultBuf);
	//
	RDebug::ProfileResult(&result,9,1);
	resultBuf.Format(_L("Door::Construct::OpenAIF - Time: %D, Count: %D"),result.iTime,result.iCount);
	test.Next(resultBuf);
	//
	RDebug::ProfileResult(&result,6,1);
	resultBuf.Format(_L("Door::SetFormatToIcon() - Time: %D, Count: %D"),result.iTime,result.iCount);
	test.Next(resultBuf);
	//
	RDebug::ProfileResult(&result,8,1);
	resultBuf.Format(_L("Door::SFTI::FindAIF - Time: %D, Count: %D"),result.iTime,result.iCount);
	test.Next(resultBuf);
	//
	RDebug::ProfileResult(&result,11,1);
	resultBuf.Format(_L("Door::SFTI::CreateIcon - Time: %D, Count: %D"),result.iTime,result.iCount);
	test.Next(resultBuf);
	//
	test.Next(_L("Press a key to continue..."));
	test.Getch();
	}