os/kernelhwsrv/kerneltest/e32test/benchmark/bm_main.cpp
changeset 0 bde4ae8d615e
     1.1 --- /dev/null	Thu Jan 01 00:00:00 1970 +0000
     1.2 +++ b/os/kernelhwsrv/kerneltest/e32test/benchmark/bm_main.cpp	Fri Jun 15 03:10:57 2012 +0200
     1.3 @@ -0,0 +1,650 @@
     1.4 +// Copyright (c) 2002-2009 Nokia Corporation and/or its subsidiary(-ies).
     1.5 +// All rights reserved.
     1.6 +// This component and the accompanying materials are made available
     1.7 +// under the terms of the License "Eclipse Public License v1.0"
     1.8 +// which accompanies this distribution, and is available
     1.9 +// at the URL "http://www.eclipse.org/legal/epl-v10.html".
    1.10 +//
    1.11 +// Initial Contributors:
    1.12 +// Nokia Corporation - initial contribution.
    1.13 +//
    1.14 +// Contributors:
    1.15 +//
    1.16 +// Description:
    1.17 +// Overview:
    1.18 +// Test and benchmark kernel-side utility operations  
    1.19 +// API Information:
    1.20 +// RBusLogicalChannel			
    1.21 +// Details:
    1.22 +// - Create a list of benchmark modules and start running them one by one;
    1.23 +// each module contains a set of measurement units, each unit runs for a fixed
    1.24 +// amount of time in a series of iterations; the results, minimum, maximum and
    1.25 +// average times are displayed on the screen;
    1.26 +// The tests use a high resolution timer implemented kernel side in a device
    1.27 +// driver.
    1.28 +// - The test contains the following benchmark modules:
    1.29 +// - Real-time latency module measures:
    1.30 +// - interrupt latency by calculating the time taken from when an
    1.31 +// interrupt is generated until the ISR starts
    1.32 +// - kernel thread latency by calculating the time taken from an ISR
    1.33 +// scheduling a DFC to signal the kernel thread until the kernel thread
    1.34 +// starts running
    1.35 +// - kernel thread latency as above while a CPU intensive low priority
    1.36 +// user thread runs at the same time
    1.37 +// - user thread latency by calculating the time taken from an ISR 
    1.38 +// scheduling a DFC to signal the user thread until the user thread
    1.39 +// starts running
    1.40 +// - user thread latency as above while a CPU intensive low priority
    1.41 +// user thread runs at the same time
    1.42 +// - NTimer period jitter by calculating the actual period as the delta
    1.43 +// between two consecutive NTimer callbacks that store the current time;
    1.44 +// the jitter is the difference between the actual period and a theoretical
    1.45 +// period.
    1.46 +// - timer overhead by calculating the delta of time between two consecutive
    1.47 +// timestamps requested from the high precision timer implemented in the
    1.48 +// device driver; the calls are made from kernel side code
    1.49 +// - Overhead module measures:
    1.50 +// - timer overhead by calculating the delta of time between two consecutive
    1.51 +// timestamps requested from the high precision timer implemented in the
    1.52 +// device driver; the calls are made from user side code
    1.53 +// - Synchronization module measures: 
    1.54 +// - mutex passing, local mutex contention, remote mutex contention, 
    1.55 +// local semaphore latency, remote semaphore latency, 
    1.56 +// local thread semaphore latency, remote thread semaphore latency.
    1.57 +// - Client-server framework module measures:
    1.58 +// - For local high priority, local low priority, remote high priority 
    1.59 +// and remote low priority: connection request latency, connection
    1.60 +// reply latency, request latency, request response time, reply latency.
    1.61 +// - Threads modules measures:
    1.62 +// - Thread creation latency, thread creation suicide, thread suicide,
    1.63 +// thread killing, setting per thread data, getting per thread data.
    1.64 +// - Properties module measures:
    1.65 +// - Local int notification latency, remote int notification latency, 
    1.66 +// local byte(1) notification latency, remote byte(1) notification latency, 
    1.67 +// local byte(8) notification latency, remote byte(8) notification latency, 
    1.68 +// local byte(512) notification latency, remote byte(512) notification latency, 
    1.69 +// int set overhead, byte(1) set overhead, byte(8) set overhead, byte(512) set 
    1.70 +// overhead, int get overhead, byte(1) get overhead, byte(8) get overhead, 
    1.71 +// byte(512) get overhead. 
    1.72 +// Platforms/Drives/Compatibility:
    1.73 +// All.
    1.74 +// Assumptions/Requirement/Pre-requisites:
    1.75 +// Failures and causes:
    1.76 +// Base Port information:
    1.77 +// 
    1.78 +//
    1.79 +
    1.80 +#include "bm_suite.h"
    1.81 +#include <e32svr.h>
    1.82 +#include <u32hal.h>
    1.83 +
    1.84 +RTest test(_L("Benchmark Suite"));
    1.85 +
    1.86 +//
    1.87 +// The default value of the time allocated for one benchmark program.  
    1.88 +//
    1.89 +static TInt KBMSecondsPerProgram = 30;
    1.90 +//
    1.91 +// The initial number of iterations to estimate the acctual number of iteration. 
    1.92 +//
    1.93 +static TInt KBMCalibrationIter = 64;
    1.94 +
    1.95 +//
    1.96 +// Global handle to high-resolution timer. 
    1.97 +//
    1.98 +RBMTimer bmTimer;
    1.99 +//
   1.100 +// The head of the benchmark programs' list
   1.101 +//
   1.102 +BMProgram* bmSuite; 
   1.103 +//
   1.104 +// Global handle to the kernel side benchmark utilty API 
   1.105 +//
   1.106 +static RBMDriver bmDriver;
   1.107 +
   1.108 +TBMResult::TBMResult(const TDesC& aName) : iName(aName) 
   1.109 +	{
   1.110 +	Reset();
   1.111 +	}
   1.112 +
   1.113 +void TBMResult::Reset()
   1.114 +	{
   1.115 +	::bmTimer.Period(&iMinTicks);
   1.116 +	iMaxTicks = 0;
   1.117 +	iCumulatedTicks = 0;
   1.118 +	iCumulatedIterations = 0;
   1.119 +	iIterations = 0;
   1.120 +	iMin = 0;
   1.121 +	iMax = 0;
   1.122 +	iAverage = 0;
   1.123 +	}
   1.124 +
   1.125 +void TBMResult::Reset(const TDesC& aName)
   1.126 +	{
   1.127 +	Reset();
   1.128 +	iName.Set(aName);
   1.129 +	}
   1.130 +
   1.131 +void TBMResult::Cumulate(TBMTicks aTicks)
   1.132 +{
   1.133 +	if (aTicks < iMinTicks) iMinTicks = aTicks;
   1.134 +	if (iMaxTicks < aTicks) iMaxTicks = aTicks;
   1.135 +
   1.136 +	iCumulatedTicks += aTicks;
   1.137 +	if (iCumulatedIterations < KHeadSize)
   1.138 +		{
   1.139 +		iHeadTicks[iCumulatedIterations] = aTicks;
   1.140 +		}
   1.141 +		// use the array as a circular buufer to store last KTailSize results
   1.142 +		// (would not really know which one was actually the last)
   1.143 +	iTailTicks[iCumulatedIterations % KTailSize] = aTicks;
   1.144 +	++iCumulatedIterations;
   1.145 +	
   1.146 +}
   1.147 +
   1.148 +
   1.149 +void TBMResult::Cumulate(TBMTicks aTicks, TBMUInt64 aIter)
   1.150 +{
   1.151 +	iCumulatedIterations += aIter;
   1.152 +	iCumulatedTicks += aTicks;
   1.153 +}
   1.154 +
   1.155 +void TBMResult::Update()
   1.156 +{
   1.157 +	if (iCumulatedIterations == 0) return;
   1.158 +	iIterations = iCumulatedIterations;
   1.159 +	::bmTimer.TicksToNs(&iMinTicks, &iMin);
   1.160 +	::bmTimer.TicksToNs(&iMaxTicks, &iMax);
   1.161 +	TBMTicks averageTicks = iCumulatedTicks/TBMUInt64(iCumulatedIterations);
   1.162 +	::bmTimer.TicksToNs(&averageTicks, &iAverage);
   1.163 +	TInt i;
   1.164 +	for (i = 0; i < KHeadSize; ++i) 
   1.165 +		{
   1.166 +		::bmTimer.TicksToNs(&iHeadTicks[i], &iHead[i]);
   1.167 +		}
   1.168 +	for (i = 0; i < KTailSize; ++i) 
   1.169 +		{
   1.170 +		::bmTimer.TicksToNs(&iTailTicks[i], &iTail[i]);
   1.171 +		}
   1.172 +	}
   1.173 +
   1.174 +inline TBMNs TTimeIntervalMicroSecondsToTBMNs(TTimeIntervalMicroSeconds us)
   1.175 +	{
   1.176 +	return BMUsToNs(*(TBMUInt64*)&us);
   1.177 +	}
   1.178 +
   1.179 +TBMNs TBMTimeInterval::iStampPeriodNs;
   1.180 +TBMTicks TBMTimeInterval::iStampPeriod;
   1.181 +
   1.182 +void TBMTimeInterval::Init()
   1.183 +	{
   1.184 +	::bmTimer.Period(&iStampPeriod); 
   1.185 +	::bmTimer.TicksToNs(&iStampPeriod, &iStampPeriodNs);
   1.186 +}
   1.187 +
   1.188 +void TBMTimeInterval::Begin()
   1.189 +	{
   1.190 +	//
   1.191 +	// Order is important: read first low-precision timer, then the high-precision one. 
   1.192 +	// Therefore, two high-precision timer reads will be accounted in the low-precision interval,
   1.193 +	// that's better than the opposite.
   1.194 +	//
   1.195 +	iTime.HomeTime();
   1.196 +	::bmTimer.Stamp(&iStamp);
   1.197 +	}
   1.198 +
   1.199 +TBMNs TBMTimeInterval::EndNs()
   1.200 +	{
   1.201 +	//
   1.202 +	// Now, in the reverse order
   1.203 +	//
   1.204 +	TBMTicks stamp;
   1.205 +	::bmTimer.Stamp(&stamp);
   1.206 +	TTime time;	
   1.207 +	time.HomeTime();
   1.208 +	TBMNs ns = TTimeIntervalMicroSecondsToTBMNs(time.MicroSecondsFrom(iTime));
   1.209 +	//
   1.210 +	// If the interval fits in the high-precision timer period we can use it;
   1.211 +	// otherwise, use the low-precision timer.
   1.212 +	//
   1.213 +	if (ns < iStampPeriodNs)
   1.214 +		{
   1.215 +		stamp = TBMTicksDelta(iStamp, stamp);
   1.216 +		::bmTimer.TicksToNs(&stamp, &ns);
   1.217 +		}
   1.218 +	return ns;
   1.219 +	}
   1.220 +
   1.221 +TBMTicks TBMTimeInterval::End()
   1.222 +	{
   1.223 +	//
   1.224 +	// The same as the previous one but returns ticks
   1.225 +	//
   1.226 +
   1.227 +	TBMTicks stamp;
   1.228 +	::bmTimer.Stamp(&stamp);
   1.229 +	TTime time;	
   1.230 +	time.HomeTime();
   1.231 +	TBMNs ns = TTimeIntervalMicroSecondsToTBMNs(time.MicroSecondsFrom(iTime));
   1.232 +	if (ns < iStampPeriodNs)
   1.233 +		{
   1.234 +		stamp = TBMTicksDelta(iStamp, stamp);
   1.235 +		}
   1.236 +	else
   1.237 +		{
   1.238 +			// multiply first - privileging precision to improbable overflow.
   1.239 +		stamp = (ns * iStampPeriod) / iStampPeriodNs; 
   1.240 +		}
   1.241 +	return stamp;
   1.242 +	}
   1.243 +
   1.244 +TInt BMProgram::SetAbsPriority(RThread aThread, TInt aNewPrio)
   1.245 +	{
   1.246 +	TInt aOldPrio=0;
   1.247 +	TInt r = ::bmDriver.SetAbsPriority(aThread, aNewPrio, &aOldPrio);
   1.248 +	BM_ERROR(r, r == KErrNone);
   1.249 +	return aOldPrio;
   1.250 +	}
   1.251 +
   1.252 +const TInt TBMSpawnArgs::KMagic = 0xdeadbeef;
   1.253 +
   1.254 +TBMSpawnArgs::TBMSpawnArgs(TThreadFunction aChildFunc, TInt aChildPrio, TBool aRemote, TInt aSize)
   1.255 +	{
   1.256 +	iMagic = KMagic;
   1.257 +	iParentId = RThread().Id();
   1.258 +		// get a thread handle meaningful in the context of any other thread. 
   1.259 +		// (RThread() doesn't work since contextual!)
   1.260 +	TInt r = iParent.Open(iParentId);
   1.261 +	BM_ERROR(r, r == KErrNone);
   1.262 +	iRemote = aRemote;
   1.263 +	iChildFunc = aChildFunc;
   1.264 +	iChildPrio = aChildPrio;
   1.265 +	iSize = aSize;
   1.266 +	}
   1.267 +
   1.268 +TBMSpawnArgs::~TBMSpawnArgs()
   1.269 +	{
   1.270 +	iParent.Close();
   1.271 +	}
   1.272 +
   1.273 +//
   1.274 +// An object of CLocalChild class represents a "child" thread created by its "parent" thread 
   1.275 +// in the parent's process through BmProgram::SpawnChild() interface.
   1.276 +//
   1.277 +// CLocalChild class is typically used (invoked) by the parent's thread. 
   1.278 +//
   1.279 +class CLocalChild : public CBase, public MBMChild
   1.280 +	{
   1.281 +private:
   1.282 +	BMProgram*		iProg;
   1.283 +public:
   1.284 +	RThread			iChild;
   1.285 +	TRequestStatus	iExitStatus;
   1.286 +
   1.287 +	CLocalChild(BMProgram* aProg)
   1.288 +		{
   1.289 +		iProg = aProg;
   1.290 +		}
   1.291 +	
   1.292 +	virtual void WaitChildExit();
   1.293 +	virtual void Kill();
   1.294 +	};
   1.295 +
   1.296 +void CLocalChild::Kill()
   1.297 +	{
   1.298 +	iChild.Kill(KErrCancel);
   1.299 +	}
   1.300 +
   1.301 +void CLocalChild::WaitChildExit()
   1.302 +	{
   1.303 +	User::WaitForRequest(iExitStatus);
   1.304 +	CLOSE_AND_WAIT(iChild);
   1.305 +	//
   1.306 +	// Lower the parent thread prioirty and then restore the current one 
   1.307 +	// to make sure that the kernel-side thread destruction DFC had a chance to complete.
   1.308 +	//
   1.309 +	TInt prio = BMProgram::SetAbsPriority(RThread(), iProg->iOrigAbsPriority);
   1.310 +	BMProgram::SetAbsPriority(RThread(), prio);
   1.311 +	delete this;
   1.312 +	}
   1.313 +
   1.314 +//
   1.315 +// Local (i.e. sharing the parent's process) child's entry point
   1.316 +//
   1.317 +TInt LocalChildEntry(void* ptr)
   1.318 +	{
   1.319 +	TBMSpawnArgs* args = (TBMSpawnArgs*) ptr;
   1.320 +	args->iChildOrigPriority = BMProgram::SetAbsPriority(RThread(), args->iChildPrio);
   1.321 +	return args->iChildFunc(args);
   1.322 +	}
   1.323 +
   1.324 +MBMChild* BMProgram::SpawnLocalChild(TBMSpawnArgs* args)
   1.325 +	{
   1.326 +	CLocalChild* child = new CLocalChild(this);
   1.327 +	BM_ERROR(KErrNoMemory, child);
   1.328 +	TInt r = child->iChild.Create(KNullDesC, ::LocalChildEntry, 0x2000, NULL, args);
   1.329 +	BM_ERROR(r, r == KErrNone);
   1.330 +	child->iChild.Logon(child->iExitStatus);
   1.331 +	child->iChild.Resume();
   1.332 +	return child;
   1.333 +	}
   1.334 +
   1.335 +//
   1.336 +// An object of CRemoteChild class represents a "child" thread created by its "parent" thread 
   1.337 +// as a separate process through BmProgram::SpawnChild() interface.
   1.338 +//
   1.339 +// CRemoteChild class is typically used (invoked) by the parent's thread. 
   1.340 +//
   1.341 +class CRemoteChild : public CBase, public MBMChild
   1.342 +	{
   1.343 +private:
   1.344 +	BMProgram*		iProg;
   1.345 +public:
   1.346 +	RProcess		iChild;
   1.347 +	TRequestStatus	iExitStatus;
   1.348 +
   1.349 +	CRemoteChild(BMProgram* aProg)
   1.350 +		{
   1.351 +		iProg = aProg;
   1.352 +		}
   1.353 +
   1.354 +	virtual void WaitChildExit();
   1.355 +	virtual void Kill();
   1.356 +	};
   1.357 +
   1.358 +void CRemoteChild::Kill()
   1.359 +	{
   1.360 +	iChild.Kill(KErrCancel);
   1.361 +	}
   1.362 +
   1.363 +void CRemoteChild::WaitChildExit()
   1.364 +	{
   1.365 +	User::WaitForRequest(iExitStatus);
   1.366 +	CLOSE_AND_WAIT(iChild);
   1.367 +	//
   1.368 +	// Lower the parent thread prioirty and then restore the current one 
   1.369 +	// to make sure that the kernel-side thread destruction DFC had a chance to complete.
   1.370 +	//
   1.371 +	TInt prio = BMProgram::SetAbsPriority(RThread(), iProg->iOrigAbsPriority);
   1.372 +	BMProgram::SetAbsPriority(RThread(), prio);
   1.373 +	delete this;
   1.374 +	}
   1.375 +
   1.376 +//
   1.377 +// Remote (i.e. running in its own process) child's entry point.
   1.378 +// Note that the child's process entry point is still E32Main() process (see below)
   1.379 +//
   1.380 +TInt ChildMain(TBMSpawnArgs* args)
   1.381 +	{
   1.382 +	args->iChildOrigPriority = BMProgram::SetAbsPriority(RThread(), args->iChildPrio);
   1.383 +		// get a handle to the parent's thread in the child's context.
   1.384 +	TInt r = args->iParent.Open(args->iParentId);
   1.385 +	BM_ERROR(r, r == KErrNone);
   1.386 +	return args->iChildFunc(args);
   1.387 +	}
   1.388 +
   1.389 +MBMChild* BMProgram::SpawnRemoteChild(TBMSpawnArgs* args)
   1.390 +	{
   1.391 +	CRemoteChild* child = new CRemoteChild(this);
   1.392 +	BM_ERROR(KErrNoMemory, child);
   1.393 +	//
   1.394 +	// Create the child process and pass args as a UNICODE command line.
   1.395 +	// (we suppose that the args size is multiple of sizeof(TUint16))
   1.396 +	//
   1.397 +	BM_ASSERT((args->iSize % sizeof(TUint16)) == 0);
   1.398 +	TInt r = child->iChild.Create(RProcess().FileName(), TPtrC((TUint16*) args, args->iSize/sizeof(TUint16)));
   1.399 +	BM_ERROR(r, (r == KErrNone) );
   1.400 +	child->iChild.Logon(child->iExitStatus);
   1.401 +	child->iChild.Resume();
   1.402 +	return child;
   1.403 +	}
   1.404 +
   1.405 +MBMChild* BMProgram::SpawnChild(TBMSpawnArgs* args)
   1.406 +	{
   1.407 +	MBMChild* child;
   1.408 +	if (args->iRemote)
   1.409 +		{
   1.410 +		child = SpawnRemoteChild(args);
   1.411 +		}
   1.412 +	else
   1.413 +		{
   1.414 +		child = SpawnLocalChild(args);
   1.415 +		}
   1.416 +	return child;
   1.417 +	}
   1.418 +
   1.419 +//
   1.420 +// The benchmark-suite entry point.
   1.421 +//
   1.422 +GLDEF_C TInt E32Main()
   1.423 +	{
   1.424 +	test.Title();
   1.425 +
   1.426 +	TInt r = UserSvr::HalFunction(EHalGroupKernel, EKernelHalNumLogicalCpus, 0, 0);
   1.427 +	if (r != 1)
   1.428 +		{
   1.429 +		test.Printf(_L("%d CPUs detected ... test not run\n"), r);
   1.430 +		return r;
   1.431 +		}
   1.432 +	
   1.433 +	AddProperty();
   1.434 +	AddThread();
   1.435 +	AddIpc();
   1.436 +	AddSync();
   1.437 +	AddOverhead();
   1.438 +	AddrtLatency();
   1.439 +
   1.440 +	r = User::LoadPhysicalDevice(KBMPddFileName);
   1.441 +	BM_ERROR(r, (r == KErrNone) || (r == KErrAlreadyExists));
   1.442 +
   1.443 +	r = User::LoadLogicalDevice(KBMLddFileName);
   1.444 +	BM_ERROR(r, (r == KErrNone) || (r == KErrAlreadyExists));
   1.445 +
   1.446 +	r = ::bmTimer.Open();
   1.447 +	BM_ERROR(r, (r == KErrNone));
   1.448 +
   1.449 +	r = ::bmDriver.Open();
   1.450 +	BM_ERROR(r, (r == KErrNone));
   1.451 +
   1.452 +	TBMTimeInterval::Init();
   1.453 +
   1.454 +	TInt seconds = KBMSecondsPerProgram;
   1.455 +
   1.456 +	TInt len = User::CommandLineLength();
   1.457 +	if (len)
   1.458 +		{
   1.459 +		//
   1.460 +		// Copy the command line in a buffer
   1.461 +		//
   1.462 +		TInt size = len * sizeof(TUint16);
   1.463 +		HBufC8* hb = HBufC8::NewMax(size);
   1.464 +		BM_ERROR(KErrNoMemory, hb);
   1.465 +		TPtr cmd((TUint16*) hb->Ptr(), len);
   1.466 +		User::CommandLine(cmd);
   1.467 +		//
   1.468 +		// Check for the TBMSpawnArgs magic number.
   1.469 +		//
   1.470 +		TBMSpawnArgs* args = (TBMSpawnArgs*) hb->Ptr();	
   1.471 +		if (args->iMagic == TBMSpawnArgs::KMagic)
   1.472 +			{
   1.473 +			//
   1.474 +			// This is a child process -  call it's entry point
   1.475 +			//
   1.476 +			return ::ChildMain(args);
   1.477 +			}
   1.478 +		else
   1.479 +			{
   1.480 +			//
   1.481 +			// A real command line - the time (in seconds) for each benchmark program.
   1.482 +			//
   1.483 +			TLex l(cmd);
   1.484 +			r = l.Val(seconds);
   1.485 +			if (r != KErrNone)
   1.486 +				{
   1.487 +				test.Printf(_L("Usage: bm_suite <seconds>\n"));
   1.488 +				BM_ERROR(r, 0);
   1.489 +				}
   1.490 +			}
   1.491 +		delete hb;
   1.492 +		}
   1.493 +
   1.494 +	{
   1.495 +	TBMTicks ticks = 1;
   1.496 +	TBMNs ns;
   1.497 +	::bmTimer.TicksToNs(&ticks, &ns);
   1.498 +	test.Printf(_L("High resolution timer tick %dns\n"), TInt(ns));
   1.499 +	test.Printf(_L("High resolution timer period %dms\n"), BMNsToMs(TBMTimeInterval::iStampPeriodNs));
   1.500 +	}
   1.501 +
   1.502 +	test.Start(_L("Performance Benchmark Suite"));
   1.503 +
   1.504 +	BMProgram* prog = ::bmSuite;
   1.505 +	while (prog) {
   1.506 +		//
   1.507 +		// For each program from the benchmark-suite's list
   1.508 +		//
   1.509 +
   1.510 +		//
   1.511 +		// Remember the number of open handles. Just for a sanity check ....
   1.512 +		//
   1.513 +		TInt start_thc, start_phc;
   1.514 +		RThread().HandleCount(start_phc, start_thc);
   1.515 +
   1.516 +		test.Printf(_L("%S\n"), &prog->Name());
   1.517 +	
   1.518 +		//
   1.519 +		// A benchmark-suite's thread can run at any of three possible absolute priorities:
   1.520 +		//		KBMPriorityLow, KBMPriorityMid and KBMPriorityHigh.
   1.521 +		// The main thread starts individual benchmark programs at KBMPriorityMid
   1.522 +		//
   1.523 +		prog->iOrigAbsPriority = BMProgram::SetAbsPriority(RThread(), KBMPriorityMid);
   1.524 +
   1.525 +		//
   1.526 +		// First of all figure out how many iteration would be required to run this program
   1.527 +		// for the given number of seconds.
   1.528 +		//
   1.529 +		TInt count;
   1.530 +		TBMNs ns = 0;
   1.531 +		TBMUInt64 iter = KBMCalibrationIter;
   1.532 +		for (;;) 
   1.533 +			{
   1.534 +			TBMTimeInterval ti;
   1.535 +			ti.Begin();
   1.536 +			prog->Run(iter, &count);
   1.537 +			ns = ti.EndNs();
   1.538 +				// run at least 100ms (otherwise, could be too much impricise ...)
   1.539 +			if (ns > BMMsToNs(100)) break;
   1.540 +			iter *= 2;
   1.541 +			}
   1.542 +		test.Printf(_L("%d iterations in %dms\n"), TInt(iter), BMNsToMs(ns));
   1.543 +		iter = (BMSecondsToNs(seconds) * iter) / ns;
   1.544 +		test.Printf(_L("Go for %d iterations ...\n"), TInt(iter));
   1.545 +
   1.546 +		//
   1.547 +		// Now the real run ...
   1.548 +		//
   1.549 +		TBMResult* results = prog->Run(iter, &count);
   1.550 +
   1.551 +			// Restore the original prioirty
   1.552 +		BMProgram::SetAbsPriority(RThread(), prog->iOrigAbsPriority);
   1.553 +
   1.554 +		//
   1.555 +		// Now print out the results
   1.556 +		//
   1.557 +		for (TInt i = 0; i < count; ++i) 
   1.558 +			{
   1.559 +			if (results[i].iMax)
   1.560 +				{
   1.561 +				test.Printf(_L("%S. %d iterations; Avr: %dns; Min: %dns; Max: %dns\n"), 
   1.562 +							&results[i].iName, TInt(results[i].iIterations),
   1.563 +							TInt(results[i].iAverage), TInt(results[i].iMin), TInt(results[i].iMax));
   1.564 +
   1.565 +				TInt j;
   1.566 +				BM_ASSERT((TBMResult::KHeadSize % 4) == 0);
   1.567 +				test.Printf(_L("Head:"));
   1.568 +				for (j = 0; j < TBMResult::KHeadSize; j += 4)
   1.569 +					{
   1.570 +					test.Printf(_L(" %d %d %d %d "), 
   1.571 +								TInt(results[i].iHead[j]), TInt(results[i].iHead[j+1]), 
   1.572 +								TInt(results[i].iHead[j+2]), TInt(results[i].iHead[j+3]));
   1.573 +					}
   1.574 +				test.Printf(_L("\n"));
   1.575 +
   1.576 +				BM_ASSERT((TBMResult::KTailSize % 4) == 0);
   1.577 +				test.Printf(_L("Tail:"));
   1.578 +				for (j = 0; j < TBMResult::KTailSize; j += 4)
   1.579 +					{
   1.580 +					test.Printf(_L(" %d %d %d %d "), 
   1.581 +								TInt(results[i].iTail[j]), TInt(results[i].iTail[j+1]), 
   1.582 +								TInt(results[i].iTail[j+2]), TInt(results[i].iTail[j+3]));
   1.583 +					}
   1.584 +				test.Printf(_L("\n"));
   1.585 +				}
   1.586 +			else
   1.587 +				{
   1.588 +				test.Printf(_L("%S. %d iterations; Avr: %dns\n"), 
   1.589 +							&results[i].iName, TInt(results[i].iIterations), TInt(results[i].iAverage));
   1.590 +				}
   1.591 +
   1.592 +			}
   1.593 +
   1.594 +		//
   1.595 +		// Sanity check for open handles
   1.596 +		//
   1.597 +		TInt end_thc, end_phc;
   1.598 +		RThread().HandleCount(end_phc, end_thc);
   1.599 +		BM_ASSERT(start_thc == end_thc);
   1.600 +		BM_ASSERT(start_phc == end_phc);
   1.601 +			// and also for pending requests ...
   1.602 +		BM_ASSERT(RThread().RequestCount() == 0);
   1.603 +
   1.604 +		prog = prog->Next();
   1.605 +//
   1.606 +//		This can be used to run forever ...
   1.607 +//
   1.608 +//		if (prog == NULL)
   1.609 +//			prog = ::bmSuite;
   1.610 +//
   1.611 +	}
   1.612 +	
   1.613 +	test.End();
   1.614 +
   1.615 +	::bmDriver.Close();
   1.616 +	::bmTimer.Close();
   1.617 +	return 0;
   1.618 +	}
   1.619 +
   1.620 +
   1.621 +void bm_assert_failed(char* aCond, char* aFile, TInt aLine)
   1.622 +	{
   1.623 +	TPtrC8 fd((TUint8*)aFile);
   1.624 +	TPtrC8 cd((TUint8*)aCond);
   1.625 +
   1.626 +	HBufC* fhb = HBufC::NewMax(fd.Length());
   1.627 +	test(fhb != 0);
   1.628 +	HBufC* chb = HBufC::NewMax(cd.Length());
   1.629 +	test(chb != 0);
   1.630 +
   1.631 +	fhb->Des().Copy(fd);
   1.632 +	chb->Des().Copy(cd);
   1.633 +
   1.634 +	test.Printf(_L("Assertion %S failed;  File: %S; Line %d;\n"), chb, fhb, aLine);
   1.635 +	test(0);
   1.636 +	}
   1.637 +
   1.638 +void bm_error_detected(TInt aError, char* aCond, char* aFile, TInt aLine)
   1.639 +	{
   1.640 +	TPtrC8 fd((TUint8*)aFile);
   1.641 +	TPtrC8 cd((TUint8*)aCond);
   1.642 +
   1.643 +	HBufC* fhb = HBufC::NewMax(fd.Length());
   1.644 +	test(fhb != 0);
   1.645 +	HBufC* chb = HBufC::NewMax(cd.Length());
   1.646 +	test(chb != 0);
   1.647 +
   1.648 +	fhb->Des().Copy(fd);
   1.649 +	chb->Des().Copy(cd);
   1.650 +
   1.651 +	test.Printf(_L("Error: %d; Cond: %S; File: %S; Line %d;\n"), aError, chb, fhb, aLine);
   1.652 +	test(0);
   1.653 +	}