// Copyright (c) 2005-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"

// which accompanies this distribution, and is available

// at the URL "http://www.eclipse.org/legal/epl-v10.html".

//

// Initial Contributors:

// Nokia Corporation - initial contribution.

//

// Contributors:

//

// Description:

// Example CTestStep derived implementation

// 

//

/**

 @file te_uloggermclperfstep.cpp

 @internalTechnology

*/

#include "te_uloggermclperfstep.h"

#include "te_uloggermclsuitedefs.h"

#include <e32math.h>

using namespace Ulogger;

////////////////////////////////////////////////////////////////////////

////////////////////////////////////////////////////////////////////////

//////////////////////////////////USER SIDE/////////////////////////////

////////////////////////////////////////////////////////////////////////

////////////////////////////////////////////////////////////////////////

CULoggerMCLUserPerfStep::~CULoggerMCLUserPerfStep()

/**

 * Destructor

 */

	{

	}

CULoggerMCLUserPerfStep::CULoggerMCLUserPerfStep()

/**

 * Constructor

 */

	{

		SetTestStepName(KULoggerMCLUserPerfStep);

	}

TVerdict CULoggerMCLUserPerfStep::doTestStepPreambleL()

/**

 * @return - TVerdict code

 * Override of base class virtual

 */

	{

		INFO_PRINTF1(_L("Carrying out performance testing on user side tracing for file and serial plugins"));

		SetTestStepResult(EPass);

		return TestStepResult();

	}

TVerdict CULoggerMCLUserPerfStep::doTestStepL()

/**

 * @return - TVerdict code

 * Override of base class pure virtual

 * Our implementation only gets called if the base class doTestStepPreambleL() did

 * not leave. That being the case, the current test result value will be EPass.

 */

	{

	  	if (TestStepResult()==EPass)

		{

		//  ************** Delete the Block, the block start ****************

			INFO_PRINTF1(_L("Benchmark trace logging for the file plug-in"));

			 __CREATE_LOG(true);

			 __HIRES_RESOLUTION;

			TInt fastTimerFreq;

			HAL::Get(HALData::EFastCounterFrequency, fastTimerFreq);

			TReal ticksPerMicroSec = 1.0E-6 * fastTimerFreq;	

			TUint32 prevTime;

			TUint32 timeDiff;

			TReal timeSpentToTrace;

			bool ret=1;

			CUTraces Testtracer;

			TUTrace TestTraceObject(UTracePrimary, UTraceSecondary, schema, context, pc);

			TInt Result=0;

			/***Now set file plugins and filter settings****/

			RULogger logger;

			logger.Connect();

			CClearConfig configIni;

			CArrayFixFlat<TUint8> *setprimfilter = new (ELeave)CArrayFixFlat<TUint8>(1);

			setprimfilter->AppendL(UTracePrimary);

			RArray<TUint32> setsecondfilter;

			setsecondfilter.Append((TUint32) UTraceSecondary);

			logger.SetPrimaryFiltersEnabled(*setprimfilter,ETrue);

			logger.SetSecondaryFiltersEnabled(setsecondfilter,ETrue);

			///////////////////////////////////////////////////////////

			///////////////////////////////////////////////////////////

			/////////////////////////FILE//////////////////////////////

			///////////////////////////////////////////////////////////

			///////////////////////////////////////////////////////////

			INFO_PRINTF1(_L("about to set file as output plugin"));

			//NB: this of course assumes that the plugin functionality works which is tested more rigorously in the plugin test step

			if(Result==0)	

			{

				INFO_PRINTF1(_L("file set as output plugin ok"));

				_LIT8(KTextmedia,"uloggerfileplugin");

				TPtrC8 mediaptr(KTextmedia);

				Result=logger.ActivateOutputPlugin(mediaptr);

				if(Result==0||Result==-11)

				{	

					INFO_PRINTF1(_L("file set as active output plugin ok"));

					_LIT(KTextsetting, "output_path");

					_LIT(KTextvalue, "c:\\logs\\ULoggerPerfUserSideFileLogging.log");

					TPluginConfiguration setPluginConfigs;

					setPluginConfigs.SetKey(KTextsetting);

					setPluginConfigs.SetValue(KTextvalue);

					Result=logger.SetPluginConfigurations(mediaptr, setPluginConfigs);

					if(Result==0)

						INFO_PRINTF1(_L("output plugin settings set ok"));

					else

						INFO_PRINTF1(_L("setting output plugin settings failed"));

				}

				else

					INFO_PRINTF1(_L("file not set as active output plugin - failed"));

			}

			else

				INFO_PRINTF1(_L("add file as output plugin failed"));

			/***Now carry out performance benchmarking and tracing for NonStatic SET method to file****/

			__LOG("Trace times for 10,000 user side nonstatic set traces logging to file plugin");

#ifdef FILE_PERF	

			for(int tracetag=0;tracetag!=NumberOfUTraceMacros;tracetag++)

			{

				logger.Start();

 			 	__LOG("NONStatic Trace ID: ")

 			 	__LOGNUM(tracetag)	 

				ret = 0;

				timeDiff=0;

				for(int i=0;i!=StatAverage;i++)

				{

					User::After(Math::Random()%100000);

					prevTime = User::FastCounter();

					for(int i=0;i!=UTrace_Cache_Count;i++)

						ret = Testtracer.DoTheSetTrace(tracetag, TestTraceObject);

					timeDiff += User::FastCounter() - prevTime;

				}

				timeSpentToTrace = timeDiff/ticksPerMicroSec/StatAverage;

				INFO_PRINTF5(_L("Utrace macro %d trace, size %d (%d trace(s))= %10.6lf microseconds"), tracetag, Testtracer.SizeOfTrace(tracetag), UTrace_Cache_Count, timeSpentToTrace);

				INFO_PRINTF2(_L("Time per trace = %10.6e microseconds"),timeSpentToTrace/UTrace_Count );

				logger.Stop();

			}

			if(ret==0)

				INFO_PRINTF1(_L("tracing failed from UTrace"));

			/***Now carry out performance benchmarking and tracing for Static method to file****/

			__LOG("Trace times for 10,000 user side static traces logging to file plugin");

			for(int tracetag=0;tracetag!=NumberOfUTraceMacros;tracetag++)

			{

				logger.Start();

 			 	__LOG("Static Trace ID: ")

 			 	__LOGNUM(tracetag)	 

				ret = 0;

				timeDiff=0;

				for(int i=0;i!=StatAverage;i++)

				{

					User::After(Math::Random()%100000);

					prevTime = User::FastCounter();

					for(int i=0;i!=UTrace_Cache_Count;i++)

						ret = Testtracer.DoTheStaticTrace(tracetag);

					timeDiff += User::FastCounter() - prevTime;

				}

				timeSpentToTrace = timeDiff/ticksPerMicroSec/StatAverage;

				INFO_PRINTF5(_L("Utrace macro %d trace, size %d (%d trace(s))= %10.6lf microseconds"), tracetag, Testtracer.SizeOfTrace(tracetag), UTrace_Cache_Count, timeSpentToTrace);

				INFO_PRINTF2(_L("Time per trace = %10.6e microseconds"),timeSpentToTrace/UTrace_Count );

				logger.Stop();

			}

			if(ret==0)

				INFO_PRINTF1(_L("tracing failed from UTrace"));

#endif	//file

			///////////////////////////////////////////////////////////

			///////////////////////////////////////////////////////////

			////////////////////////SERIAL/////////////////////////////

			///////////////////////////////////////////////////////////

			///////////////////////////////////////////////////////////

			INFO_PRINTF1(_L("Now benchmark trace logging for the serial plug-in"));

			// adding a plugin

			_LIT8(KSerialTextmedia,"uloggerserialplugin");

			TPtrC8 serialmediaptr(KSerialTextmedia);

			Result=logger.ActivateOutputPlugin(serialmediaptr);

			if(Result==0)			

			{	

			// test the added plugin can be activated

				if(Result==0||Result==-11)	

				{	

					INFO_PRINTF1(_L("Serial Plugin active"));

					_LIT(KSerialTextsetting, "output_port");	

					_LIT(KSerialTextvalue, "3");

					// test setting the plugin settings

					TPluginConfiguration setSerialPluginConfigs;

					setSerialPluginConfigs.SetKey(KSerialTextsetting);

					setSerialPluginConfigs.SetValue(KSerialTextvalue);				

					Result=logger.SetPluginConfigurations(serialmediaptr, setSerialPluginConfigs);

					if(Result==0)	

					{

						INFO_PRINTF1(_L("Serial Plugin Settings set correctly"));

					}

				}

				else

					INFO_PRINTF1(_L("Serial plugin not set as active plugin"));

			}

			__LOG("Trace times for 10,000 user side nonstatic traces logging to serial plugin");

			/***Now carry out performance benchmarking and tracing for nonstatic set method to serial****/

#ifdef SERIAL_PERF

#ifndef __WINSCW__			

			for(int tracetag=0;tracetag!=NumberOfUTraceMacros;tracetag++)

			{

				logger.Start();

 			 	__LOG("NONStatic Trace ID: ")

 			 	__LOGNUM(tracetag)	 

				ret = 0;

				timeDiff=0;

				for(int i=0;i!=StatAverage;i++)

				{

					User::After(Math::Random()%100000);

					prevTime = User::FastCounter();

					for(int i=0;i!=UTrace_Cache_Count;i++)

						ret = Testtracer.DoTheSetTrace(tracetag, TestTraceObject);

					timeDiff += User::FastCounter() - prevTime;

				}

				timeSpentToTrace = timeDiff/ticksPerMicroSec/StatAverage;

				INFO_PRINTF5(_L("Utrace macro %d trace, size %d (%d trace(s))= %10.6lf microseconds"), tracetag, Testtracer.SizeOfTrace(tracetag), UTrace_Cache_Count, timeSpentToTrace);

				INFO_PRINTF2(_L("Time per trace = %10.6e microseconds"),timeSpentToTrace/UTrace_Count );

				logger.Stop();

			}

			if(ret==0)

			INFO_PRINTF1(_L("tracing failed from UTrace"));

			__LOG("Trace times for 10,000 user side static traces logging to serial plugin");

				for(int tracetag=0;tracetag!=NumberOfUTraceMacros;tracetag++)

			{

				logger.Start();

 			 	__LOG("Static Trace ID: ")

 			 	__LOGNUM(tracetag)	 

				ret = 0;

				timeDiff=0;

				for(int i=0;i!=StatAverage;i++)

				{

					User::After(Math::Random()%100000);

					prevTime = User::FastCounter();

					for(int i=0;i!=UTrace_Cache_Count;i++)

						ret = Testtracer.DoTheStaticTrace(tracetag);

					timeDiff += User::FastCounter() - prevTime;

				}

				timeSpentToTrace = timeDiff/ticksPerMicroSec/StatAverage;

				INFO_PRINTF5(_L("Utrace macro %d trace, size %d (%d trace(s))= %10.6lf microseconds"), tracetag, Testtracer.SizeOfTrace(tracetag), UTrace_Cache_Count, timeSpentToTrace);

				INFO_PRINTF2(_L("Time per trace = %10.6e microseconds"),timeSpentToTrace/UTrace_Count );

				logger.Stop();

			}

			if(ret==0)

			INFO_PRINTF1(_L("tracing failed from UTrace"));

#endif //winscw

#endif //serial

			//  **************   Block end ****************

			if(ret==0||Result==1)

				SetTestStepResult(EFail);

			else

				SetTestStepResult(EPass);

		}

	 	return TestStepResult();

	}

TVerdict CULoggerMCLUserPerfStep::doTestStepPostambleL()

/**

 * @return - TVerdict code

 * Override of base class virtual

 */

	{

		INFO_PRINTF1(_L("Completed performance testing on user side tracing for file and serial plugins"));

		return TestStepResult();

	}

////////////////////////////////////////////////////////////////////////

////////////////////////////////////////////////////////////////////////

//////////////////////////////////KERNEL SIDE///////////////////////////

////////////////////////////////////////////////////////////////////////

////////////////////////////////////////////////////////////////////////

CULoggerMCLKernelPerfStep::~CULoggerMCLKernelPerfStep()

/**

 * Destructor

 */

	{

	}

CULoggerMCLKernelPerfStep::CULoggerMCLKernelPerfStep()

/**

 * Constructor

 */

	{

		SetTestStepName(KULoggerMCLKernelPerfStep);

	}

TVerdict CULoggerMCLKernelPerfStep::doTestStepPreambleL()

/**

 * @return - TVerdict code

 * Override of base class virtual

 */

	{

		INFO_PRINTF1(_L("Carrying out performance testing on kernel side tracing for file and serial plugins"));

		SetTestStepResult(EPass);

		return TestStepResult();

	}

TVerdict CULoggerMCLKernelPerfStep::doTestStepL()

/**

 * @return - TVerdict code

 * Override of base class pure virtual

 * Our implementation only gets called if the base class doTestStepPreambleL() did

 * not leave. That being the case, the current test result value will be EPass.

 */

	{

		if (TestStepResult()==EPass)

		{

			//  ************** Delete the Block, the block start ****************

#ifndef __WINSCW__			

			INFO_PRINTF1(_L("Benchmark trace logging for the file plug-in"));

			 __CREATE_LOG(true);

			 __HIRES_RESOLUTION;

			TInt fastTimerFreq;

			HAL::Get(HALData::EFastCounterFrequency, fastTimerFreq);

			TReal ticksPerMicroSec = 1.0E-6 * fastTimerFreq;	

			TUint32 prevTime;

			TUint32 timeDiff;

			TReal timeSpentToTrace;	

			CUKernelTraces TestKerneltracer;

			TInt Result=0;

			/***Now set file plugins and filter settings****/

			RULogger logger;

			logger.Connect();

			CClearConfig configIni;	

			CArrayFixFlat<TUint8> *setprimfilter = new (ELeave)CArrayFixFlat<TUint8>(1);

			setprimfilter->AppendL(UTracePrimary);

			RArray<TUint32> setsecondfilter;

			setsecondfilter.Append((TUint32) UTraceSecondary);		

			logger.SetPrimaryFiltersEnabled(*setprimfilter,ETrue);

			logger.SetSecondaryFiltersEnabled(setsecondfilter,ETrue);

			/**Load usb device**/

			TInt ret = KErrNone;

			ret =User::LoadLogicalDevice(_L("eusbc.ldd"));

			if(ret == KErrAlreadyExists)

			ret = KErrNone;	

			RDevUsbcClient usbDevice;

			usbDevice.Open(0);	

			///////////////////////////////////////////////////////////

			///////////////////////////////////////////////////////////

			/////////////////////////FILE//////////////////////////////

			///////////////////////////////////////////////////////////

			///////////////////////////////////////////////////////////

			INFO_PRINTF1(_L("about to set file as output plugin"));

			//NB: this of course assumes that the plugin functionality works which is tested more rigorously in the plugin test step

			if(Result==0)	

			{

				INFO_PRINTF1(_L("file set as output plugin ok"));

				_LIT8(KTextmedia,"uloggerfileplugin");

				TPtrC8 mediaptr(KTextmedia);

				Result=logger.ActivateOutputPlugin(mediaptr);				

				if(Result==0||Result==-11)

				{	

					INFO_PRINTF1(_L("file set as active output plugin ok"));

					_LIT(KTextsetting, "output_path");

					_LIT(KTextvalue, "c:\\logs\\ULoggerPerfKernelSideFileLogging.log");

					TPluginConfiguration setPluginConfigs;

					setPluginConfigs.SetKey(KTextsetting);

					setPluginConfigs.SetValue(KTextvalue);				

					Result=logger.SetPluginConfigurations(mediaptr, setPluginConfigs);

					if(Result==0)

						INFO_PRINTF1(_L("output plugin settings set ok"));

					else

						INFO_PRINTF1(_L("setting output plugin settings failed"));

				}

				else

					INFO_PRINTF1(_L("file not set as active output plugin - failed"));

			}

			else

				INFO_PRINTF1(_L("add file as output plugin failed"));

			/***Now carry out performance benchmarking and tracing for NonStatic SET method to file****/

			__LOG("Trace times for 10,000 kernel side nonstatic set traces logging to file plugin");

#ifdef FILE_PERF	

			for(int tracetag=0;tracetag!=NumberOfUTraceMacros;tracetag++)

			{

				logger.Start();

			 	__LOG("NONStatic Trace ID: ")

			 	__LOGNUM(tracetag)	 

				ret = 0;

				timeDiff=0;

				for(int i=0;i!=StatAverage;i++)

				{

					User::After(Math::Random()%100000);

					prevTime = User::FastCounter();

					for(int i=0;i!=UTrace_Cache_Count;i++)

						ret = TestKerneltracer.DoTheKernelSetTrace(tracetag, usbDevice);

					timeDiff += User::FastCounter() - prevTime;

				}

				timeSpentToTrace = timeDiff/ticksPerMicroSec/StatAverage;

				INFO_PRINTF5(_L("Utrace macro %d trace, size %d (%d trace(s))= %10.6lf microseconds"), tracetag, TestKerneltracer.SizeOfKernelTrace(tracetag), UTrace_Cache_Count, timeSpentToTrace);

				INFO_PRINTF2(_L("Time per trace = %10.6e microseconds"),timeSpentToTrace/UTrace_Count );

				logger.Stop();

			}

			if(ret==0)

				INFO_PRINTF1(_L("device driver returned error, but tracing should still be carried out"));

			/***Now carry out performance benchmarking and tracing for Static method to file****/

			__LOG("Trace times for 10,000 kernel side static traces logging to file plugin");

			for(int tracetag=0;tracetag!=NumberOfUTraceMacros;tracetag++)

			{

				logger.Start();

			 	__LOG("Static Trace ID: ")

			 	__LOGNUM(tracetag)	 

				ret = 0;

				timeDiff=0;

				for(int i=0;i!=StatAverage;i++)

				{

					User::After(Math::Random()%100000);

					prevTime = User::FastCounter();

					for(int i=0;i!=UTrace_Cache_Count;i++)

						ret = TestKerneltracer.DoTheKernelStaticTrace(tracetag, usbDevice);

					timeDiff += User::FastCounter() - prevTime;

				}

				timeSpentToTrace = timeDiff/ticksPerMicroSec/StatAverage;

				INFO_PRINTF5(_L("Utrace macro %d trace, size %d (%d trace(s))= %10.6lf microseconds"), tracetag, TestKerneltracer.SizeOfKernelTrace(tracetag), UTrace_Cache_Count, timeSpentToTrace);

				INFO_PRINTF2(_L("Time per trace = %10.6e microseconds"),timeSpentToTrace/UTrace_Count );

				logger.Stop();

			}

			if(ret==0)

				INFO_PRINTF1(_L("device driver returned error, but tracing should still be carried out"));

#endif	//file

		///////////////////////////////////////////////////////////

		///////////////////////////////////////////////////////////

		////////////////////////SERIAL/////////////////////////////

		///////////////////////////////////////////////////////////

		///////////////////////////////////////////////////////////

			INFO_PRINTF1(_L("Now benchmark trace logging for the serial plug-in"));

			_LIT8(KSerialTextmedia,"uloggerserialplugin");

			TPtrC8 serialmediaptr(KSerialTextmedia);

			Result=logger.ActivateOutputPlugin(serialmediaptr);				

			if(Result==0||Result==-11)			

			{	

				// test the added plugin can be activated			

				if(Result==0)	

				{	

					INFO_PRINTF1(_L("Serial Plugin active"));

					_LIT(KSerialTextsetting, "output_port");

					_LIT(KSerialTextvalue, "3");

					// test setting the plugin settings

					TPluginConfiguration setSerialPluginConfigs;

					setSerialPluginConfigs.SetKey(KSerialTextsetting);

					setSerialPluginConfigs.SetValue(KSerialTextvalue);

					Result=logger.SetPluginConfigurations(serialmediaptr, setSerialPluginConfigs);

					if(Result==0)	

					{

						INFO_PRINTF1(_L("Serial Plugin Settings set correctly"));

					}	

				}

				else

					INFO_PRINTF1(_L("Serial plugin not set as active plugin"));

			}

			else

				INFO_PRINTF1(_L("Serial plugin not added as output plugin"));

			/***Now carry out performance benchmarking and tracing for NonStatic SET method to serial****/

			__LOG("Trace times for 10,000 kernel side nonstatic set traces logging to serial plugin");

#ifdef SERIAL_PERF

			for(int tracetag=0;tracetag!=NumberOfUTraceMacros;tracetag++)

			{

				logger.Start();

			 	__LOG("NONStatic Trace ID: ")

			 	__LOGNUM(tracetag)	 

				ret = 0;

				timeDiff=0;

				for(int i=0;i!=StatAverage;i++)

				{

					User::After(Math::Random()%100000);

					prevTime = User::FastCounter();

					for(int i=0;i!=UTrace_Cache_Count;i++)

						ret = TestKerneltracer.DoTheKernelSetTrace(tracetag, usbDevice);

					timeDiff += User::FastCounter() - prevTime;

				}

				timeSpentToTrace = timeDiff/ticksPerMicroSec/StatAverage;

				INFO_PRINTF5(_L("Utrace macro %d trace, size %d (%d trace(s))= %10.6lf microseconds"), tracetag, TestKerneltracer.SizeOfKernelTrace(tracetag), UTrace_Cache_Count, timeSpentToTrace);

				INFO_PRINTF2(_L("Time per trace = %10.6e microseconds"),timeSpentToTrace/UTrace_Count );

				logger.Stop();

			}

			if(ret==0)

				INFO_PRINTF1(_L("device driver returned error, but tracing should still be carried out"));

			/***Now carry out performance benchmarking and tracing for Static method to file****/

			__LOG("Trace times for 10,000 kernel side static traces logging to serial plugin");

			for(int tracetag=0;tracetag!=NumberOfUTraceMacros;tracetag++)

			{

				logger.Start();

			 	__LOG("Static Trace ID: ")

			 	__LOGNUM(tracetag)	 

				ret = 0;

				timeDiff=0;

				for(int i=0;i!=StatAverage;i++)

				{

					User::After(Math::Random()%100000);

					prevTime = User::FastCounter();

					for(int i=0;i!=UTrace_Cache_Count;i++)

						ret = TestKerneltracer.DoTheKernelStaticTrace(tracetag, usbDevice);

					timeDiff += User::FastCounter() - prevTime;

				}

				timeSpentToTrace = timeDiff/ticksPerMicroSec/StatAverage;

				INFO_PRINTF5(_L("Utrace macro %d trace, size %d (%d trace(s))= %10.6lf microseconds"), tracetag, TestKerneltracer.SizeOfKernelTrace(tracetag), UTrace_Cache_Count, timeSpentToTrace);

				INFO_PRINTF2(_L("Time per trace = %10.6e microseconds"),timeSpentToTrace/UTrace_Count );

				logger.Stop();

			}

			if(ret==0)

				INFO_PRINTF1(_L("device driver returned error, but tracing should still be carried out"));