1 // Copyright (c) 2002-2009 Nokia Corporation and/or its subsidiary(-ies).

     2 // All rights reserved.

     3 // This component and the accompanying materials are made available

     4 // under the terms of the License "Eclipse Public License v1.0"

     5 // which accompanies this distribution, and is available

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

     7 //

     8 // Initial Contributors:

     9 // Nokia Corporation - initial contribution.

    10 //

    11 // Contributors:

    12 //

    13 // Description:

    14 // Overview:

    15 // Test and benchmark kernel-side utility operations  

    16 // API Information:

    17 // RBusLogicalChannel			

    18 // Details:

    19 // - Create a list of benchmark modules and start running them one by one;

    20 // each module contains a set of measurement units, each unit runs for a fixed

    21 // amount of time in a series of iterations; the results, minimum, maximum and

    22 // average times are displayed on the screen;

    23 // The tests use a high resolution timer implemented kernel side in a device

    24 // driver.

    25 // - The test contains the following benchmark modules:

    26 // - Real-time latency module measures:

    27 // - interrupt latency by calculating the time taken from when an

    28 // interrupt is generated until the ISR starts

    29 // - kernel thread latency by calculating the time taken from an ISR

    30 // scheduling a DFC to signal the kernel thread until the kernel thread

    31 // starts running

    32 // - kernel thread latency as above while a CPU intensive low priority

    33 // user thread runs at the same time

    34 // - user thread latency by calculating the time taken from an ISR 

    35 // scheduling a DFC to signal the user thread until the user thread

    36 // starts running

    37 // - user thread latency as above while a CPU intensive low priority

    38 // user thread runs at the same time

    39 // - NTimer period jitter by calculating the actual period as the delta

    40 // between two consecutive NTimer callbacks that store the current time;

    41 // the jitter is the difference between the actual period and a theoretical

    42 // period.

    43 // - timer overhead by calculating the delta of time between two consecutive

    44 // timestamps requested from the high precision timer implemented in the

    45 // device driver; the calls are made from kernel side code

    46 // - Overhead module measures:

    47 // - timer overhead by calculating the delta of time between two consecutive

    48 // timestamps requested from the high precision timer implemented in the

    49 // device driver; the calls are made from user side code

    50 // - Synchronization module measures: 

    51 // - mutex passing, local mutex contention, remote mutex contention, 

    52 // local semaphore latency, remote semaphore latency, 

    53 // local thread semaphore latency, remote thread semaphore latency.

    54 // - Client-server framework module measures:

    55 // - For local high priority, local low priority, remote high priority 

    56 // and remote low priority: connection request latency, connection

    57 // reply latency, request latency, request response time, reply latency.

    58 // - Threads modules measures:

    59 // - Thread creation latency, thread creation suicide, thread suicide,

    60 // thread killing, setting per thread data, getting per thread data.

    61 // - Properties module measures:

    62 // - Local int notification latency, remote int notification latency, 

    63 // local byte(1) notification latency, remote byte(1) notification latency, 

    64 // local byte(8) notification latency, remote byte(8) notification latency, 

    65 // local byte(512) notification latency, remote byte(512) notification latency, 

    66 // int set overhead, byte(1) set overhead, byte(8) set overhead, byte(512) set 

    67 // overhead, int get overhead, byte(1) get overhead, byte(8) get overhead, 

    68 // byte(512) get overhead. 

    69 // Platforms/Drives/Compatibility:

    70 // All.

    71 // Assumptions/Requirement/Pre-requisites:

    72 // Failures and causes:

    73 // Base Port information:

    74 // 

    75 //

    76 

    77 #include "bm_suite.h"

    78 #include <e32svr.h>

    79 #include <u32hal.h>

    80 

    81 RTest test(_L("Benchmark Suite"));

    82 

    83 //

    84 // The default value of the time allocated for one benchmark program.  

    85 //

    86 static TInt KBMSecondsPerProgram = 30;

    87 //

    88 // The initial number of iterations to estimate the acctual number of iteration. 

    89 //

    90 static TInt KBMCalibrationIter = 64;

    91 

    92 //

    93 // Global handle to high-resolution timer. 

    94 //

    95 RBMTimer bmTimer;

    96 //

    97 // The head of the benchmark programs' list

    98 //

    99 BMProgram* bmSuite; 

   100 //

   101 // Global handle to the kernel side benchmark utilty API 

   102 //

   103 static RBMDriver bmDriver;

   104 

   105 TBMResult::TBMResult(const TDesC& aName) : iName(aName) 

   106 	{

   107 	Reset();

   108 	}

   109 

   110 void TBMResult::Reset()

   111 	{

   112 	::bmTimer.Period(&iMinTicks);

   113 	iMaxTicks = 0;

   114 	iCumulatedTicks = 0;

   115 	iCumulatedIterations = 0;

   116 	iIterations = 0;

   117 	iMin = 0;

   118 	iMax = 0;

   119 	iAverage = 0;

   120 	}

   121 

   122 void TBMResult::Reset(const TDesC& aName)

   123 	{

   124 	Reset();

   125 	iName.Set(aName);

   126 	}

   127 

   128 void TBMResult::Cumulate(TBMTicks aTicks)

   129 {

   130 	if (aTicks < iMinTicks) iMinTicks = aTicks;

   131 	if (iMaxTicks < aTicks) iMaxTicks = aTicks;

   132 

   133 	iCumulatedTicks += aTicks;

   134 	if (iCumulatedIterations < KHeadSize)

   135 		{

   136 		iHeadTicks[iCumulatedIterations] = aTicks;

   137 		}

   138 		// use the array as a circular buufer to store last KTailSize results

   139 		// (would not really know which one was actually the last)

   140 	iTailTicks[iCumulatedIterations % KTailSize] = aTicks;

   141 	++iCumulatedIterations;

   142 	

   143 }

   144 

   145 

   146 void TBMResult::Cumulate(TBMTicks aTicks, TBMUInt64 aIter)

   147 {

   148 	iCumulatedIterations += aIter;

   149 	iCumulatedTicks += aTicks;

   150 }

   151 

   152 void TBMResult::Update()

   153 {

   154 	if (iCumulatedIterations == 0) return;

   155 	iIterations = iCumulatedIterations;

   156 	::bmTimer.TicksToNs(&iMinTicks, &iMin);

   157 	::bmTimer.TicksToNs(&iMaxTicks, &iMax);

   158 	TBMTicks averageTicks = iCumulatedTicks/TBMUInt64(iCumulatedIterations);

   159 	::bmTimer.TicksToNs(&averageTicks, &iAverage);

   160 	TInt i;

   161 	for (i = 0; i < KHeadSize; ++i) 

   162 		{

   163 		::bmTimer.TicksToNs(&iHeadTicks[i], &iHead[i]);

   164 		}

   165 	for (i = 0; i < KTailSize; ++i) 

   166 		{

   167 		::bmTimer.TicksToNs(&iTailTicks[i], &iTail[i]);

   168 		}

   169 	}

   170 

   171 inline TBMNs TTimeIntervalMicroSecondsToTBMNs(TTimeIntervalMicroSeconds us)

   172 	{

   173 	return BMUsToNs(*(TBMUInt64*)&us);

   174 	}

   175 

   176 TBMNs TBMTimeInterval::iStampPeriodNs;

   177 TBMTicks TBMTimeInterval::iStampPeriod;

   178 

   179 void TBMTimeInterval::Init()

   180 	{

   181 	::bmTimer.Period(&iStampPeriod); 

   182 	::bmTimer.TicksToNs(&iStampPeriod, &iStampPeriodNs);

   183 }

   184 

   185 void TBMTimeInterval::Begin()

   186 	{

   187 	//

   188 	// Order is important: read first low-precision timer, then the high-precision one. 

   189 	// Therefore, two high-precision timer reads will be accounted in the low-precision interval,

   190 	// that's better than the opposite.

   191 	//

   192 	iTime.HomeTime();

   193 	::bmTimer.Stamp(&iStamp);

   194 	}

   195 

   196 TBMNs TBMTimeInterval::EndNs()

   197 	{

   198 	//

   199 	// Now, in the reverse order

   200 	//

   201 	TBMTicks stamp;

   202 	::bmTimer.Stamp(&stamp);

   203 	TTime time;	

   204 	time.HomeTime();

   205 	TBMNs ns = TTimeIntervalMicroSecondsToTBMNs(time.MicroSecondsFrom(iTime));

   206 	//

   207 	// If the interval fits in the high-precision timer period we can use it;

   208 	// otherwise, use the low-precision timer.

   209 	//

   210 	if (ns < iStampPeriodNs)

   211 		{

   212 		stamp = TBMTicksDelta(iStamp, stamp);

   213 		::bmTimer.TicksToNs(&stamp, &ns);

   214 		}

   215 	return ns;

   216 	}

   217 

   218 TBMTicks TBMTimeInterval::End()

   219 	{

   220 	//

   221 	// The same as the previous one but returns ticks

   222 	//

   223 

   224 	TBMTicks stamp;

   225 	::bmTimer.Stamp(&stamp);

   226 	TTime time;	

   227 	time.HomeTime();

   228 	TBMNs ns = TTimeIntervalMicroSecondsToTBMNs(time.MicroSecondsFrom(iTime));

   229 	if (ns < iStampPeriodNs)

   230 		{

   231 		stamp = TBMTicksDelta(iStamp, stamp);

   232 		}

   233 	else

   234 		{

   235 			// multiply first - privileging precision to improbable overflow.

   236 		stamp = (ns * iStampPeriod) / iStampPeriodNs; 

   237 		}

   238 	return stamp;

   239 	}

   240 

   241 TInt BMProgram::SetAbsPriority(RThread aThread, TInt aNewPrio)

   242 	{

   243 	TInt aOldPrio=0;

   244 	TInt r = ::bmDriver.SetAbsPriority(aThread, aNewPrio, &aOldPrio);

   245 	BM_ERROR(r, r == KErrNone);

   246 	return aOldPrio;

   247 	}

   248 

   249 const TInt TBMSpawnArgs::KMagic = 0xdeadbeef;

   250 

   251 TBMSpawnArgs::TBMSpawnArgs(TThreadFunction aChildFunc, TInt aChildPrio, TBool aRemote, TInt aSize)

   252 	{

   253 	iMagic = KMagic;

   254 	iParentId = RThread().Id();

   255 		// get a thread handle meaningful in the context of any other thread. 

   256 		// (RThread() doesn't work since contextual!)

   257 	TInt r = iParent.Open(iParentId);

   258 	BM_ERROR(r, r == KErrNone);

   259 	iRemote = aRemote;

   260 	iChildFunc = aChildFunc;

   261 	iChildPrio = aChildPrio;

   262 	iSize = aSize;

   263 	}

   264 

   265 TBMSpawnArgs::~TBMSpawnArgs()

   266 	{

   267 	iParent.Close();

   268 	}

   269 

   270 //

   271 // An object of CLocalChild class represents a "child" thread created by its "parent" thread 

   272 // in the parent's process through BmProgram::SpawnChild() interface.

   273 //

   274 // CLocalChild class is typically used (invoked) by the parent's thread. 

   275 //

   276 class CLocalChild : public CBase, public MBMChild

   277 	{

   278 private:

   279 	BMProgram*		iProg;

   280 public:

   281 	RThread			iChild;

   282 	TRequestStatus	iExitStatus;

   283 

   284 	CLocalChild(BMProgram* aProg)

   285 		{

   286 		iProg = aProg;

   287 		}

   288 	

   289 	virtual void WaitChildExit();

   290 	virtual void Kill();

   291 	};

   292 

   293 void CLocalChild::Kill()

   294 	{

   295 	iChild.Kill(KErrCancel);

   296 	}

   297 

   298 void CLocalChild::WaitChildExit()

   299 	{

   300 	User::WaitForRequest(iExitStatus);

   301 	CLOSE_AND_WAIT(iChild);

   302 	//

   303 	// Lower the parent thread prioirty and then restore the current one 

   304 	// to make sure that the kernel-side thread destruction DFC had a chance to complete.

   305 	//

   306 	TInt prio = BMProgram::SetAbsPriority(RThread(), iProg->iOrigAbsPriority);

   307 	BMProgram::SetAbsPriority(RThread(), prio);

   308 	delete this;

   309 	}

   310 

   311 //

   312 // Local (i.e. sharing the parent's process) child's entry point

   313 //

   314 TInt LocalChildEntry(void* ptr)

   315 	{

   316 	TBMSpawnArgs* args = (TBMSpawnArgs*) ptr;

   317 	args->iChildOrigPriority = BMProgram::SetAbsPriority(RThread(), args->iChildPrio);

   318 	return args->iChildFunc(args);

   319 	}

   320 

   321 MBMChild* BMProgram::SpawnLocalChild(TBMSpawnArgs* args)

   322 	{

   323 	CLocalChild* child = new CLocalChild(this);

   324 	BM_ERROR(KErrNoMemory, child);

   325 	TInt r = child->iChild.Create(KNullDesC, ::LocalChildEntry, 0x2000, NULL, args);

   326 	BM_ERROR(r, r == KErrNone);

   327 	child->iChild.Logon(child->iExitStatus);

   328 	child->iChild.Resume();

   329 	return child;

   330 	}

   331 

   332 //

   333 // An object of CRemoteChild class represents a "child" thread created by its "parent" thread 

   334 // as a separate process through BmProgram::SpawnChild() interface.

   335 //

   336 // CRemoteChild class is typically used (invoked) by the parent's thread. 

   337 //

   338 class CRemoteChild : public CBase, public MBMChild

   339 	{

   340 private:

   341 	BMProgram*		iProg;

   342 public:

   343 	RProcess		iChild;

   344 	TRequestStatus	iExitStatus;

   345 

   346 	CRemoteChild(BMProgram* aProg)

   347 		{

   348 		iProg = aProg;

   349 		}

   350 

   351 	virtual void WaitChildExit();

   352 	virtual void Kill();

   353 	};

   354 

   355 void CRemoteChild::Kill()

   356 	{

   357 	iChild.Kill(KErrCancel);

   358 	}

   359 

   360 void CRemoteChild::WaitChildExit()

   361 	{

   362 	User::WaitForRequest(iExitStatus);

   363 	CLOSE_AND_WAIT(iChild);

   364 	//

   365 	// Lower the parent thread prioirty and then restore the current one 

   366 	// to make sure that the kernel-side thread destruction DFC had a chance to complete.

   367 	//

   368 	TInt prio = BMProgram::SetAbsPriority(RThread(), iProg->iOrigAbsPriority);

   369 	BMProgram::SetAbsPriority(RThread(), prio);

   370 	delete this;

   371 	}

   372 

   373 //

   374 // Remote (i.e. running in its own process) child's entry point.

   375 // Note that the child's process entry point is still E32Main() process (see below)

   376 //

   377 TInt ChildMain(TBMSpawnArgs* args)

   378 	{

   379 	args->iChildOrigPriority = BMProgram::SetAbsPriority(RThread(), args->iChildPrio);

   380 		// get a handle to the parent's thread in the child's context.

   381 	TInt r = args->iParent.Open(args->iParentId);

   382 	BM_ERROR(r, r == KErrNone);

   383 	return args->iChildFunc(args);

   384 	}

   385 

   386 MBMChild* BMProgram::SpawnRemoteChild(TBMSpawnArgs* args)

   387 	{

   388 	CRemoteChild* child = new CRemoteChild(this);

   389 	BM_ERROR(KErrNoMemory, child);

   390 	//

   391 	// Create the child process and pass args as a UNICODE command line.

   392 	// (we suppose that the args size is multiple of sizeof(TUint16))

   393 	//

   394 	BM_ASSERT((args->iSize % sizeof(TUint16)) == 0);

   395 	TInt r = child->iChild.Create(RProcess().FileName(), TPtrC((TUint16*) args, args->iSize/sizeof(TUint16)));

   396 	BM_ERROR(r, (r == KErrNone) );

   397 	child->iChild.Logon(child->iExitStatus);

   398 	child->iChild.Resume();

   399 	return child;

   400 	}

   401 

   402 MBMChild* BMProgram::SpawnChild(TBMSpawnArgs* args)

   403 	{

   404 	MBMChild* child;

   405 	if (args->iRemote)

   406 		{

   407 		child = SpawnRemoteChild(args);

   408 		}

   409 	else

   410 		{

   411 		child = SpawnLocalChild(args);

   412 		}

   413 	return child;

   414 	}

   415 

   416 //

   417 // The benchmark-suite entry point.

   418 //

   419 GLDEF_C TInt E32Main()

   420 	{

   421 	test.Title();

   422 

   423 	TInt r = UserSvr::HalFunction(EHalGroupKernel, EKernelHalNumLogicalCpus, 0, 0);

   424 	if (r != 1)

   425 		{

   426 		test.Printf(_L("%d CPUs detected ... test not run\n"), r);

   427 		return r;

   428 		}

   429 	

   430 	AddProperty();

   431 	AddThread();

   432 	AddIpc();

   433 	AddSync();

   434 	AddOverhead();

   435 	AddrtLatency();

   436 

   437 	r = User::LoadPhysicalDevice(KBMPddFileName);

   438 	BM_ERROR(r, (r == KErrNone) || (r == KErrAlreadyExists));

   439 

   440 	r = User::LoadLogicalDevice(KBMLddFileName);

   441 	BM_ERROR(r, (r == KErrNone) || (r == KErrAlreadyExists));

   442 

   443 	r = ::bmTimer.Open();

   444 	BM_ERROR(r, (r == KErrNone));

   445 

   446 	r = ::bmDriver.Open();

   447 	BM_ERROR(r, (r == KErrNone));

   448 

   449 	TBMTimeInterval::Init();

   450 

   451 	TInt seconds = KBMSecondsPerProgram;

   452 

   453 	TInt len = User::CommandLineLength();

   454 	if (len)

   455 		{

   456 		//

   457 		// Copy the command line in a buffer

   458 		//

   459 		TInt size = len * sizeof(TUint16);

   460 		HBufC8* hb = HBufC8::NewMax(size);

   461 		BM_ERROR(KErrNoMemory, hb);

   462 		TPtr cmd((TUint16*) hb->Ptr(), len);

   463 		User::CommandLine(cmd);

   464 		//

   465 		// Check for the TBMSpawnArgs magic number.

   466 		//

   467 		TBMSpawnArgs* args = (TBMSpawnArgs*) hb->Ptr();	

   468 		if (args->iMagic == TBMSpawnArgs::KMagic)

   469 			{

   470 			//

   471 			// This is a child process -  call it's entry point

   472 			//

   473 			return ::ChildMain(args);

   474 			}

   475 		else

   476 			{

   477 			//

   478 			// A real command line - the time (in seconds) for each benchmark program.

   479 			//

   480 			TLex l(cmd);

   481 			r = l.Val(seconds);

   482 			if (r != KErrNone)

   483 				{

   484 				test.Printf(_L("Usage: bm_suite <seconds>\n"));

   485 				BM_ERROR(r, 0);

   486 				}

   487 			}

   488 		delete hb;

   489 		}

   490 

   491 	{

   492 	TBMTicks ticks = 1;

   493 	TBMNs ns;

   494 	::bmTimer.TicksToNs(&ticks, &ns);

   495 	test.Printf(_L("High resolution timer tick %dns\n"), TInt(ns));

   496 	test.Printf(_L("High resolution timer period %dms\n"), BMNsToMs(TBMTimeInterval::iStampPeriodNs));

   497 	}

   498 

   499 	test.Start(_L("Performance Benchmark Suite"));

   500 

   501 	BMProgram* prog = ::bmSuite;

   502 	while (prog) {

   503 		//

   504 		// For each program from the benchmark-suite's list

   505 		//

   506 

   507 		//

   508 		// Remember the number of open handles. Just for a sanity check ....

   509 		//

   510 		TInt start_thc, start_phc;

   511 		RThread().HandleCount(start_phc, start_thc);

   512 

   513 		test.Printf(_L("%S\n"), &prog->Name());

   514 	

   515 		//

   516 		// A benchmark-suite's thread can run at any of three possible absolute priorities:

   517 		//		KBMPriorityLow, KBMPriorityMid and KBMPriorityHigh.

   518 		// The main thread starts individual benchmark programs at KBMPriorityMid

   519 		//

   520 		prog->iOrigAbsPriority = BMProgram::SetAbsPriority(RThread(), KBMPriorityMid);

   521 

   522 		//

   523 		// First of all figure out how many iteration would be required to run this program

   524 		// for the given number of seconds.

   525 		//

   526 		TInt count;

   527 		TBMNs ns = 0;

   528 		TBMUInt64 iter = KBMCalibrationIter;

   529 		for (;;) 

   530 			{

   531 			TBMTimeInterval ti;

   532 			ti.Begin();

   533 			prog->Run(iter, &count);

   534 			ns = ti.EndNs();

   535 				// run at least 100ms (otherwise, could be too much impricise ...)

   536 			if (ns > BMMsToNs(100)) break;

   537 			iter *= 2;

   538 			}

   539 		test.Printf(_L("%d iterations in %dms\n"), TInt(iter), BMNsToMs(ns));

   540 		iter = (BMSecondsToNs(seconds) * iter) / ns;

   541 		test.Printf(_L("Go for %d iterations ...\n"), TInt(iter));

   542 

   543 		//

   544 		// Now the real run ...

   545 		//

   546 		TBMResult* results = prog->Run(iter, &count);

   547 

   548 			// Restore the original prioirty

   549 		BMProgram::SetAbsPriority(RThread(), prog->iOrigAbsPriority);

   550 

   551 		//

   552 		// Now print out the results

   553 		//

   554 		for (TInt i = 0; i < count; ++i) 

   555 			{

   556 			if (results[i].iMax)

   557 				{

   558 				test.Printf(_L("%S. %d iterations; Avr: %dns; Min: %dns; Max: %dns\n"), 

   559 							&results[i].iName, TInt(results[i].iIterations),

   560 							TInt(results[i].iAverage), TInt(results[i].iMin), TInt(results[i].iMax));

   561 

   562 				TInt j;

   563 				BM_ASSERT((TBMResult::KHeadSize % 4) == 0);

   564 				test.Printf(_L("Head:"));

   565 				for (j = 0; j < TBMResult::KHeadSize; j += 4)

   566 					{

   567 					test.Printf(_L(" %d %d %d %d "), 

   568 								TInt(results[i].iHead[j]), TInt(results[i].iHead[j+1]), 

   569 								TInt(results[i].iHead[j+2]), TInt(results[i].iHead[j+3]));

   570 					}

   571 				test.Printf(_L("\n"));

   572 

   573 				BM_ASSERT((TBMResult::KTailSize % 4) == 0);

   574 				test.Printf(_L("Tail:"));

   575 				for (j = 0; j < TBMResult::KTailSize; j += 4)

   576 					{

   577 					test.Printf(_L(" %d %d %d %d "), 

   578 								TInt(results[i].iTail[j]), TInt(results[i].iTail[j+1]), 

   579 								TInt(results[i].iTail[j+2]), TInt(results[i].iTail[j+3]));

   580 					}

   581 				test.Printf(_L("\n"));

   582 				}

   583 			else

   584 				{

   585 				test.Printf(_L("%S. %d iterations; Avr: %dns\n"), 

   586 							&results[i].iName, TInt(results[i].iIterations), TInt(results[i].iAverage));

   587 				}

   588 

   589 			}

   590 

   591 		//

   592 		// Sanity check for open handles

   593 		//

   594 		TInt end_thc, end_phc;

   595 		RThread().HandleCount(end_phc, end_thc);

   596 		BM_ASSERT(start_thc == end_thc);

   597 		BM_ASSERT(start_phc == end_phc);

   598 			// and also for pending requests ...

   599 		BM_ASSERT(RThread().RequestCount() == 0);

   600 

   601 		prog = prog->Next();

   602 //

   603 //		This can be used to run forever ...

   604 //

   605 //		if (prog == NULL)

   606 //			prog = ::bmSuite;

   607 //

   608 	}

   609 	

   610 	test.End();

   611 

   612 	::bmDriver.Close();

   613 	::bmTimer.Close();

   614 	return 0;

   615 	}

   616 

   617 

   618 void bm_assert_failed(char* aCond, char* aFile, TInt aLine)

   619 	{

   620 	TPtrC8 fd((TUint8*)aFile);

   621 	TPtrC8 cd((TUint8*)aCond);

   622 

   623 	HBufC* fhb = HBufC::NewMax(fd.Length());

   624 	test(fhb != 0);

   625 	HBufC* chb = HBufC::NewMax(cd.Length());

   626 	test(chb != 0);

   627 

   628 	fhb->Des().Copy(fd);

   629 	chb->Des().Copy(cd);

   630 

   631 	test.Printf(_L("Assertion %S failed;  File: %S; Line %d;\n"), chb, fhb, aLine);

   632 	test(0);

   633 	}

   634 

   635 void bm_error_detected(TInt aError, char* aCond, char* aFile, TInt aLine)

   636 	{

   637 	TPtrC8 fd((TUint8*)aFile);

   638 	TPtrC8 cd((TUint8*)aCond);

   639 

   640 	HBufC* fhb = HBufC::NewMax(fd.Length());

   641 	test(fhb != 0);

   642 	HBufC* chb = HBufC::NewMax(cd.Length());

   643 	test(chb != 0);

   644 

   645 	fhb->Des().Copy(fd);

   646 	chb->Des().Copy(cd);

   647 

   648 	test.Printf(_L("Error: %d; Cond: %S; File: %S; Line %d;\n"), aError, chb, fhb, aLine);

   649 	test(0);

   650 	}