kerneltest/e32test/usbho/t_usbdi/src/BaseTestCase.cpp
changeset 253 d37db4dcc88d
parent 0 a41df078684a
child 257 3e88ff8f41d5
--- a/kerneltest/e32test/usbho/t_usbdi/src/BaseTestCase.cpp	Tue Aug 24 14:42:58 2010 +0100
+++ b/kerneltest/e32test/usbho/t_usbdi/src/BaseTestCase.cpp	Tue Aug 24 14:49:21 2010 +0100
@@ -1,4 +1,4 @@
-// Copyright (c) 2007-2009 Nokia Corporation and/or its subsidiary(-ies).
+// Copyright (c) 2007-2010 Nokia Corporation and/or its subsidiary(-ies).
 // All rights reserved.
 // This component and the accompanying materials are made available
 // under the terms of the License "Eclipse Public License v1.0"
@@ -21,6 +21,10 @@
 #include <d32usbdi.h>
 #include "testdebug.h"
 #include "testpolicy.h"
+#include "OstTraceDefinitions.h"
+#ifdef OST_TRACE_COMPILER_IN_USE
+#include "BaseTestCaseTraces.h"
+#endif
 
 namespace NUnitTesting_USBDI
 	{
@@ -46,45 +50,51 @@
 	iHost(aHostFlag),
 	iHostOnly(aHostOnly)
 	{
+	OstTraceFunctionEntryExt( CBASETESTCASE_CBASETESTCASE_ENTRY, this );
 	iTestCaseId.Copy(aTestCaseId);
 	CActiveScheduler::Add(this);
+	OstTraceFunctionExit1( CBASETESTCASE_CBASETESTCASE_EXIT, this );
 	}
 	
 void CBaseTestCase::BaseConstructL()
 	{
-	LOG_FUNC	
-	RDebug::Printf("Creating test case timer");
+	OstTraceFunctionEntry1( CBASETESTCASE_BASECONSTRUCTL_ENTRY, this );
+	OstTrace0(TRACE_NORMAL, CBASETESTCASE_BASECONSTRUCTL, "Creating test case timer");
 	TInt err(iTimer.CreateLocal());
 	if(err == KErrNone)
 		{
-		RDebug::Printf("Test case timer created");
+		OstTrace0(TRACE_NORMAL, CBASETESTCASE_BASECONSTRUCTL_DUP01, "Test case timer created");
 		}
 	else
 		{
-		RDebug::Printf("<Error %d> Test case timer could not be created",err);
+		OstTrace1(TRACE_NORMAL, CBASETESTCASE_BASECONSTRUCTL_DUP02, "<Error %d> Test case timer could not be created",err);
 		User::Leave(err);
 		}	
+	OstTraceFunctionExit1( CBASETESTCASE_BASECONSTRUCTL_EXIT, this );
 	}
 
 void CBaseTestCase::TimeoutIn(TInt aTimeoutPeriod)
 	{
-	LOG_FUNC
+	OstTraceFunctionEntryExt( CBASETESTCASE_TIMEOUTIN_ENTRY, this );
 	
 	CancelTimeout();
 	iTimer.After(iStatus,aTimeoutPeriod*1000000);
 	SetActive();
+	OstTraceFunctionExit1( CBASETESTCASE_TIMEOUTIN_EXIT, this );
 	}
 
 
 void CBaseTestCase::CancelTimeout()
 	{
+	OstTraceFunctionEntry1( CBASETESTCASE_CANCELTIMEOUT_ENTRY, this );
 	iTimer.Cancel();
+	OstTraceFunctionExit1( CBASETESTCASE_CANCELTIMEOUT_EXIT, this );
 	}
 
 TInt CBaseTestCase::GenerateRefFile(const TDesC& aFileName)
 	{
+	OstTraceFunctionEntryExt( CBASETESTCASE_GENERATEREFFILE_ENTRY, this );
 	
-	LOG_FUNC
 	TBuf<256> refTreeFullFileName(KGeneratedFilesPath);
 	refTreeFullFileName.Append(aFileName);	
 	refTreeFullFileName.Append(KExtensionFile);
@@ -95,7 +105,8 @@
 	if(ret!=KErrNone && ret!=KErrAlreadyExists)
 	// if already connected, ignore
 		{ 
-		RDebug::Printf("iFs.Connect fails, ret = %d", ret);
+		OstTrace1(TRACE_NORMAL, CBASETESTCASE_GENERATEREFFILE, "iFs.Connect fails, ret = %d", ret);
+		OstTraceFunctionExitExt( CBASETESTCASE_GENERATEREFFILE_EXIT, this, ret );
 		return ret;
 		}
 			
@@ -107,7 +118,8 @@
 	
 	if(ret!=KErrNone) 
 		{ 
-		RDebug::Printf("refFile.Create fails, ret = %d", ret);
+		OstTrace1(TRACE_NORMAL, CBASETESTCASE_GENERATEREFFILE_DUP01, "refFile.Create fails, ret = %d", ret);
+		OstTraceFunctionExitExt( CBASETESTCASE_GENERATEREFFILE_EXIT_DUP01, this, ret );
 		return ret;
 		}
 		 
@@ -115,13 +127,14 @@
 	refFile.Flush(); 
 	refFile.Close();
 			 
+	OstTraceFunctionExitExt( CBASETESTCASE_GENERATEREFFILE_EXIT_DUP02, this, KErrNone );
 	return KErrNone;
 	}	
 
 TInt CBaseTestCase::CompareCurrentTreeToRef(const TDesC& aFileName, TBool& aIsIdentical)
 	{
+	OstTraceFunctionEntryExt( CBASETESTCASE_COMPARECURRENTTREETOREF_ENTRY, this );
 	
-	LOG_FUNC								
 	TBuf<256> refTreeFullFileName(KRefPath);
 	refTreeFullFileName.Append(aFileName);
 	refTreeFullFileName.Append(KExtensionFile);	 	
@@ -131,7 +144,8 @@
 	if(ret!=KErrNone && ret!=KErrAlreadyExists)
 	// if already connected, ignore
 		{ 
-		RDebug::Printf("iFs.Connect fails, ret = %d", ret);
+		OstTrace1(TRACE_NORMAL, CBASETESTCASE_COMPARECURRENTTREETOREF, "iFs.Connect fails, ret = %d", ret);
+		OstTraceFunctionExitExt( CBASETESTCASE_COMPARECURRENTTREETOREF_EXIT, this, ret );
 		return ret;
 		}
 
@@ -140,8 +154,9 @@
 		
 	if(ret!=KErrNone)
 		{
-		RDebug::Printf("Reference File path: %S", &refTreeFullFileName);
-		RDebug::Printf("refFile.Open fails ret = %d", ret);
+		OstTraceExt1(TRACE_NORMAL, CBASETESTCASE_COMPARECURRENTTREETOREF_DUP01, "Reference File path: %S", refTreeFullFileName);
+		OstTrace1(TRACE_NORMAL, CBASETESTCASE_COMPARECURRENTTREETOREF_DUP02, "refFile.Open fails ret = %d", ret);
+		OstTraceFunctionExitExt( CBASETESTCASE_COMPARECURRENTTREETOREF_EXIT_DUP01, this, ret );
 		return ret;
 		}
 		
@@ -151,7 +166,7 @@
 	// check size is identical
 	if(refFileSize != iTreeBuffer.Size())
 		{		
-		RDebug::Printf("sizes are NOT identical, refFileSize = %d, iTreeBuffer.Size() = %d ", refFileSize, iTreeBuffer.Size());
+		OstTraceExt2(TRACE_NORMAL, CBASETESTCASE_COMPARECURRENTTREETOREF_DUP03, "sizes are NOT identical, refFileSize = %d, iTreeBuffer.Size() = %d ", refFileSize, iTreeBuffer.Size());
 		//return KErrGeneral; not an issue, \n encoded differently by perforce... x0D x0A. (x0A only in generated ref file)
 		}
 		
@@ -162,7 +177,8 @@
 
 	if(ret!=KErrNone)
 		{
-		RDebug::Printf("refFile.Read fails %d", ret);
+		OstTrace1(TRACE_NORMAL, CBASETESTCASE_COMPARECURRENTTREETOREF_DUP04, "refFile.Read fails %d", ret);
+		OstTraceFunctionExitExt( CBASETESTCASE_COMPARECURRENTTREETOREF_EXIT_DUP02, this, ret );
 		return ret;
 		}
 		
@@ -189,66 +205,73 @@
 		}
 	refBuf.Close();
 	
-	RDebug::Printf("copyRefBuf.Size %d", copyRefBuf.Size());
+	OstTrace1(TRACE_NORMAL, CBASETESTCASE_COMPARECURRENTTREETOREF_DUP05, "copyRefBuf.Size %d", copyRefBuf.Size());
 		
 
 	// check size is identical, should be identical now
 	if(copyRefBuf.Size() != iTreeBuffer.Size())
 		{		
-		RDebug::Printf("sizes are NOT identical, copyRefBuf.Size() = %d, iTreeBuffer.Size() = %d ", refFileSize, iTreeBuffer.Size());
+		OstTraceExt2(TRACE_NORMAL, CBASETESTCASE_COMPARECURRENTTREETOREF_DUP06, "sizes are NOT identical, copyRefBuf.Size() = %d, iTreeBuffer.Size() = %d ", refFileSize, iTreeBuffer.Size());
+		OstTraceFunctionExitExt( CBASETESTCASE_COMPARECURRENTTREETOREF_EXIT_DUP03, this, KErrGeneral );
 		return KErrGeneral;
 		}
 	
 	// now compare the 2 buffers		
     // Can only go as far as the smallest buffer
     TInt bufferSizeToCheck = Min(copyRefBuf.Size(), iTreeBuffer.Size());
-	RDebug::Print(_L("bufferSizeToCheck = %d"), bufferSizeToCheck);
+	OstTrace1(TRACE_NORMAL, CBASETESTCASE_COMPARECURRENTTREETOREF_DUP07, "bufferSizeToCheck = %d", bufferSizeToCheck);
 
 	aIsIdentical = ETrue;	
 	for(TInt iRefBuffer=0; iRefBuffer < bufferSizeToCheck; iRefBuffer++)
 		{
 		if(iTreeBuffer[iRefBuffer] != copyRefBuf[iRefBuffer])
 			{
-			RDebug::Print(_L("Failed buffer comparison at position %d"), iRefBuffer);
-            RDebug::Print(_L("Missmatching chars (%d %d) (%c %c)"), iTreeBuffer[iRefBuffer], copyRefBuf[iRefBuffer], iTreeBuffer[iRefBuffer], copyRefBuf[iRefBuffer]);
+			OstTrace1(TRACE_NORMAL, CBASETESTCASE_COMPARECURRENTTREETOREF_DUP08, "Failed buffer comparison at position %d", iRefBuffer);
+            OstTraceExt4(TRACE_NORMAL, CBASETESTCASE_COMPARECURRENTTREETOREF_DUP09, "Missmatching chars (%d %d) (%c %c)", iTreeBuffer[iRefBuffer], copyRefBuf[iRefBuffer], iTreeBuffer[iRefBuffer], copyRefBuf[iRefBuffer]); 
 			aIsIdentical = EFalse;
 			break;
 			}			 	 	 
 		}		
 
-	RDebug::Print(_L("Finished Buffer comparison aIsIdentical=%d"), aIsIdentical); 
+	OstTrace1(TRACE_NORMAL, CBASETESTCASE_COMPARECURRENTTREETOREF_DUP10, "Finished Buffer comparison aIsIdentical=%d", aIsIdentical); 
 
  	copyRefBuf.Close();
 	
+	OstTraceFunctionExitExt( CBASETESTCASE_COMPARECURRENTTREETOREF_EXIT_DUP04, this, KErrNone );
 	return KErrNone;	
 	}	
 
 CBaseTestCase::~CBaseTestCase()
 	{
-	LOG_FUNC
+	OstTraceFunctionEntry1( CBASETESTCASE_CBASETESTCASE_ENTRY_DUP01, this );
 	Cancel();
 	iTimer.Close();
 	iTreeBuffer.Close();
 	iFs.Close();
+	OstTraceFunctionExit1( CBASETESTCASE_CBASETESTCASE_EXIT_DUP01, this );
 	}
 
 void CBaseTestCase::SelfComplete()
 	{
+	OstTraceFunctionEntry1( CBASETESTCASE_SELFCOMPLETE_ENTRY, this );
 	SelfComplete(KErrNone);
+	OstTraceFunctionExit1( CBASETESTCASE_SELFCOMPLETE_EXIT, this );
 	}
 
 void CBaseTestCase::SelfComplete(TInt aError)
 	{
+	OstTraceFunctionEntryExt( CBASETESTCASE_SELFCOMPLETE_ENTRY_DUP01, this );
 	TRequestStatus* s = &iStatus;
 	iStatus = KRequestPending;
 	User::RequestComplete(s,aError);
 	SetActive();
+	OstTraceFunctionExit1( CBASETESTCASE_SELFCOMPLETE_EXIT_DUP01, this );
 	}
 
 
 void CBaseTestCase::DoCancel()
 	{
-	LOG_FUNC
+	OstTraceFunctionEntry1( CBASETESTCASE_DOCANCEL_ENTRY, this );
 	iTimer.Cancel();
 	if(iHost)
 		{
@@ -258,10 +281,12 @@
 		{
 		DeviceDoCancel();
 		}
+	OstTraceFunctionExit1( CBASETESTCASE_DOCANCEL_EXIT, this );
 	}
 
 void CBaseTestCase::RunL()
 	{
+	OstTraceFunctionEntry1( CBASETESTCASE_RUNL_ENTRY, this );
 	if(iHost)
 		{
 		HostRunL();
@@ -270,39 +295,50 @@
 		{
 		DeviceRunL();
 		}
+	OstTraceFunctionExit1( CBASETESTCASE_RUNL_EXIT, this );
 	}
 
 TInt CBaseTestCase::RunError(TInt aError)
 	{
-	LOG_FUNC
-	RDebug::Printf("Test case C%lS::RunL left with %d",&iTestCaseId,aError);
+	OstTraceFunctionEntryExt( CBASETESTCASE_RUNERROR_ENTRY, this );
+	OstTraceExt2(TRACE_NORMAL, CBASETESTCASE_RUNERROR, "Test case C%lS::RunL left with %d",iTestCaseId,aError);
 	iTestPolicy->SignalTestComplete(aError);
+	OstTraceFunctionExitExt( CBASETESTCASE_RUNERROR_EXIT, this, KErrNone );
 	return KErrNone;
 	}
 	
 TDesC& CBaseTestCase::TestCaseId()
 	{
+	OstTraceFunctionEntry1( CBASETESTCASE_TESTCASEID_ENTRY, this );
+	OstTraceFunctionExitExt( CBASETESTCASE_TESTCASEID_EXIT, this, ( TUint )&( iTestCaseId ) );
 	return iTestCaseId;
 	}
 	
 	
 TInt CBaseTestCase::TestResult() const
 	{
+	OstTraceFunctionEntry1( CBASETESTCASE_TESTRESULT_ENTRY, this );
+	OstTraceFunctionExitExt( CBASETESTCASE_TESTRESULT_EXIT, this, iTestResult );
 	return iTestResult;
 	}
 	
 TBool CBaseTestCase::IsHostOnly() const
 	{
+	OstTraceFunctionEntry1( CBASETESTCASE_ISHOSTONLY_ENTRY, this );
+	OstTraceFunctionExitExt( CBASETESTCASE_ISHOSTONLY_EXIT, this, iHostOnly );
 	return iHostOnly;
 	}
 		
 TBool CBaseTestCase::IsHost() const
 	{
+	OstTraceFunctionEntry1( CBASETESTCASE_ISHOST_ENTRY, this );
+	OstTraceFunctionExitExt( CBASETESTCASE_ISHOST_EXIT, this, iHost );
 	return iHost;
 	}
 		
 void CBaseTestCase::PerformTestL()
 	{
+	OstTraceFunctionEntry1( CBASETESTCASE_PERFORMTESTL_ENTRY, this );
 	
 	if(iHost)
 		{
@@ -313,37 +349,44 @@
 		{
 		ExecuteDeviceTestCaseL();
 		}	
+	OstTraceFunctionExit1( CBASETESTCASE_PERFORMTESTL_EXIT, this );
 	}
 
 void CBaseTestCase::SetTestPolicy(CBasicTestPolicy* aTestPolicy)
 	{
+	OstTraceFunctionEntryExt( CBASETESTCASE_SETTESTPOLICY_ENTRY, this );
 	iTestPolicy = aTestPolicy;
+	OstTraceFunctionExit1( CBASETESTCASE_SETTESTPOLICY_EXIT, this );
 	}
 
 void CBaseTestCase::TestFailed(TInt aFailResult)
 	{
-	LOG_FUNC
+	OstTraceFunctionEntryExt( CBASETESTCASE_TESTFAILED_ENTRY, this );
 	iTestResult = aFailResult;
 	if(!iHostOnly)
 		{
-		RDebug::Printf("CActiveScheduler::Stop CBaseTestCase::TestFailed");
+		OstTrace0(TRACE_NORMAL, CBASETESTCASE_TESTFAILED, "CActiveScheduler::Stop CBaseTestCase::TestFailed");
 		CActiveScheduler::Stop();
 		}		
+	OstTraceFunctionExit1( CBASETESTCASE_TESTFAILED_EXIT, this );
 	}
 	
 void CBaseTestCase::TestPassed()
 	{
-	LOG_FUNC
+	OstTraceFunctionEntry1( CBASETESTCASE_TESTPASSED_ENTRY, this );
 	iTestResult = KErrNone;	
 	if(!iHostOnly)
 		{
-		RDebug::Printf("CActiveScheduler::Stop CBaseTestCase::TestPassed");
+		OstTrace0(TRACE_NORMAL, CBASETESTCASE_TESTPASSED, "CActiveScheduler::Stop CBaseTestCase::TestPassed");
 		CActiveScheduler::Stop();
 		}
+	OstTraceFunctionExit1( CBASETESTCASE_TESTPASSED_EXIT, this );
 	}
 
 CBasicTestPolicy& CBaseTestCase::TestPolicy()
 	{
+	OstTraceFunctionEntry1( CBASETESTCASE_TESTPOLICY_ENTRY, this );
+	OstTraceFunctionExit1( CBASETESTCASE_TESTPOLICY_EXIT, this );
 	return *iTestPolicy;
 	}
 	
@@ -357,7 +400,7 @@
 TInt CBaseTestCase::GetEndpointAddress(RUsbInterface& aUsbInterface,TInt aInterfaceSetting,
 		TUint8 aTransferType,TUint8 aDirection,TInt& aEndpointAddress)
 	{
-	LOG_FUNC
+	OstTraceFunctionEntryExt( CBASETESTCASE_GETENDPOINTADDRESS_ENTRY, this );
 	
 	return GetEndpointAddress(aUsbInterface, aInterfaceSetting, aTransferType, aDirection, 0, aEndpointAddress);
 	}
@@ -370,46 +413,48 @@
 TInt CBaseTestCase::GetEndpointAddress(RUsbInterface& aUsbInterface,TInt aInterfaceSetting,
 		TUint8 aTransferType,TUint8 aDirection,TUint8 aIndex,TInt& aEndpointAddress)
 	{
-	LOG_FUNC
+		OstTraceFunctionEntryExt( CBASETESTCASE_GETENDPOINTADDRESS_ENTRY_DUP01, this );
 		
 	// Get the interface descriptor
-	RDebug::Printf("Getting the interface descriptor for this alternate setting");
+	OstTrace0(TRACE_NORMAL, CBASETESTCASE_GETENDPOINTADDRESS, "Getting the interface descriptor for this alternate setting");
 
 	TUsbInterfaceDescriptor alternateInterfaceDescriptor;
 	TInt err = aUsbInterface.GetAlternateInterfaceDescriptor(aInterfaceSetting, alternateInterfaceDescriptor);
 
 	if(err)
 		{
-		RDebug::Printf("<Error %d> Unable to get alternate interface (%d) descriptor",err,aInterfaceSetting);
+		OstTraceExt2(TRACE_NORMAL, CBASETESTCASE_GETENDPOINTADDRESS_DUP01, "<Error %d> Unable to get alternate interface (%d) descriptor",err,aInterfaceSetting);
+		OstTraceFunctionExitExt( CBASETESTCASE_GETENDPOINTADDRESS_EXIT, this, err );
 		return err;
 		}
 
 	// Parse the descriptor tree from the interface 	
-	RDebug::Printf("Search the child descriptors for matching endpoint attributes");
+	OstTrace0(TRACE_NORMAL, CBASETESTCASE_GETENDPOINTADDRESS_DUP02, "Search the child descriptors for matching endpoint attributes");
 	
 	TUsbGenericDescriptor* descriptor = alternateInterfaceDescriptor.iFirstChild;
 	TUint8 indexCount = 0;
 	while(descriptor)
 		{
-		RDebug::Printf("Check descriptor type for endpoint");
+		OstTrace0(TRACE_NORMAL, CBASETESTCASE_GETENDPOINTADDRESS_DUP03, "Check descriptor type for endpoint");
 
 		// Cast the descriptor to an endpoint descriptor
 		TUsbEndpointDescriptor* endpoint = TUsbEndpointDescriptor::Cast(descriptor);
 		
 		if(endpoint)
 			{
-			RDebug::Printf("Match attributes for transfer type");
+			OstTrace0(TRACE_NORMAL, CBASETESTCASE_GETENDPOINTADDRESS_DUP04, "Match attributes for transfer type");
 			
 			if( (endpoint->Attributes() & aTransferType) == aTransferType)
 				{
-				RDebug::Printf("Match attributes for endpoint direction");
+				OstTrace0(TRACE_NORMAL, CBASETESTCASE_GETENDPOINTADDRESS_DUP05, "Match attributes for endpoint direction");
 				
 				if( (endpoint->EndpointAddress() & aDirection) == aDirection) 
 					{
 					if(indexCount==aIndex)
 						{
 						aEndpointAddress = endpoint->EndpointAddress();
-						RDebug::Printf("Endpoint address found");
+						OstTrace0(TRACE_NORMAL, CBASETESTCASE_GETENDPOINTADDRESS_DUP06, "Endpoint address found");
+						OstTraceFunctionExitExt( CBASETESTCASE_GETENDPOINTADDRESS_EXIT_DUP01, this, KErrNone );
 						return KErrNone;
 						}
 					else
@@ -424,21 +469,25 @@
 		}
 
 	// Unable to find the endpoint address	
-	RDebug::Printf("Unable to find endpoint address matching the specified attributes");
+	OstTrace0(TRACE_NORMAL, CBASETESTCASE_GETENDPOINTADDRESS_DUP07, "Unable to find endpoint address matching the specified attributes");
 	
+	OstTraceFunctionExitExt( CBASETESTCASE_GETENDPOINTADDRESS_EXIT_DUP02, this, KErrNotFound );
 	return KErrNotFound;
 	}
 	
 /*static*/ void CBaseTestCase::LogWithCondAndInfo(const TDesC& aCondition, const TDesC& aFileName, TInt aLine)
 	{
+	OstTraceFunctionEntryExt( CBASETESTCASE_LOGWITHCONDANDINFO_ENTRY, 0 );
 	TBuf<256> buf;
  	buf.Format(KFailText, &aCondition, &aFileName, aLine);
- 	RDebug::Print(buf); 
+ 	OstTrace0(TRACE_NORMAL, CBASETESTCASE_GETENDPOINTADDRESS_DUP08, buf);
+ 	OstTraceFunctionExit1( CBASETESTCASE_LOGWITHCONDANDINFO_EXIT, 0 );
  	} 	
  
   	
 /*static*/ void CBaseTestCase::PrintAndStoreTree(TUsbGenericDescriptor& aDesc, TInt aDepth)
 	{ 
+	OstTraceFunctionEntryExt( CBASETESTCASE_PRINTANDSTORETREE_ENTRY, 0 );
 	
 	TBuf8<20> buf;	
 	for(TInt depth=aDepth;depth>=0;--depth)
@@ -451,12 +500,12 @@
 	unicodeBuf.Copy(buf);	// Ideally this needs conversion to UNICODE
 	if(aDesc.iRecognisedAndParsed == TUsbGenericDescriptor::ERecognised)
 		{ 
-		RDebug::Printf("%S+ length=%d, type=0x%02x", &unicodeBuf, aDesc.ibLength, aDesc.ibDescriptorType);
+		OstTraceExt3(TRACE_NORMAL, CBASETESTCASE_GETENDPOINTADDRESS_DUP09, "%s+ length=%u, type=0x%02x", unicodeBuf, aDesc.ibLength, (TUint32)aDesc.ibDescriptorType);
    		iTreeBuffer.AppendFormat(_L8("%S+ length=%d, type=0x%02x\n"), &buf, aDesc.ibLength, aDesc.ibDescriptorType);		
 		}
 	else
 		{
-		RDebug::Printf("%S- length=%d, type=0x%02x", &unicodeBuf, aDesc.ibLength, aDesc.ibDescriptorType);
+		OstTraceExt3(TRACE_NORMAL, CBASETESTCASE_GETENDPOINTADDRESS_DUP10, "%s- length=%u, type=0x%02x", unicodeBuf, aDesc.ibLength, (TUint32)aDesc.ibDescriptorType);
 		iTreeBuffer.AppendFormat(_L8("%S- length=%d, type=0x%02x\n"), &buf, aDesc.ibLength, aDesc.ibDescriptorType);
 		} 		
 
@@ -464,22 +513,24 @@
 		
 		if(aDesc.iFirstChild)    
 		{
-		RDebug::Printf("%S \\ ", &unicodeBuf);
+		OstTraceExt1(TRACE_NORMAL, CBASETESTCASE_GETENDPOINTADDRESS_DUP11, "%s \n", unicodeBuf);
 		iTreeBuffer.AppendFormat(_L8("%S \\ \n"), &buf);		
 		
 		PrintAndStoreTree(*(aDesc.iFirstChild), aDepth+1);		
 	
-		RDebug::Printf("%S / ", &unicodeBuf);
+		OstTraceExt1(TRACE_NORMAL, CBASETESTCASE_GETENDPOINTADDRESS_DUP12, "%s \n", unicodeBuf);
 		iTreeBuffer.AppendFormat(_L8("%S / \n"), &buf);
 		}
 	if(aDesc.iNextPeer)
 		{
 		PrintAndStoreTree(*(aDesc.iNextPeer), aDepth);
 		}		
+	OstTraceFunctionExit1( CBASETESTCASE_PRINTANDSTORETREE_EXIT, 0 );
 	} 
 	   
 void CBaseTestCase::PrintAndStoreBlob(TDes8& aBuf, TPtrC8& aBlob)
 	{
+	OstTraceFunctionEntryExt( CBASETESTCASE_PRINTANDSTOREBLOB_ENTRY, this );
 	
 	HBufC8* chunk = HBufC8::New(KChunkSize);
 	
@@ -504,10 +555,12 @@
 		PrintAndStoreChunk(chunk, remainderSize ,aBlob,offset, i ,aBuf);				
 		}
 	delete chunk;
+	OstTraceFunctionExit1( CBASETESTCASE_PRINTANDSTOREBLOB_EXIT, this );
 	} 
 	
 void CBaseTestCase::PrintAndStoreChunk(HBufC8* aChunk, TUint aSize, TPtrC8& aBlob, TUint aOffset, TUint aIter, TDes8& aBuf)
 	{	
+	OstTraceFunctionEntryExt( CBASETESTCASE_PRINTANDSTORECHUNK_ENTRY, this );
 	for(TInt i=0;i<aSize;++i)
 		{
 		aChunk->Des().AppendFormat(_L8("%02x"), aBlob[i+aOffset]);
@@ -520,20 +573,21 @@
 			
 	if(aIter ==0)
 		{		
-		RDebug::Printf("%S >%S", &unicodeBuf, &unicodeChunk);					
+		OstTraceExt2(TRACE_NORMAL, CBASETESTCASE_PRINTANDSTORECHUNK, "%S >%S", unicodeBuf, unicodeChunk);					
 		iTreeBuffer.AppendFormat(_L8("%S >%S\n"), &aBuf, aChunk);	
 		}
 	else
 		{	
-		RDebug::Printf("%S  %S\n", &unicodeBuf, &unicodeChunk); 
+		OstTraceExt2(TRACE_NORMAL, CBASETESTCASE_PRINTANDSTORECHUNK_DUP01, "%S  %S\n", unicodeBuf, unicodeChunk); 
 		iTreeBuffer.AppendFormat(_L8("%S  %S\n"), &aBuf, aChunk);
 		}
 	aChunk->Des().Zero();		
+	OstTraceFunctionExit1( CBASETESTCASE_PRINTANDSTORECHUNK_EXIT, this );
 	}	
 	
 TInt CBaseTestCase::CheckTree(TUsbGenericDescriptor& aDevDesc, TUsbGenericDescriptor& aConfigDesc, const TDesC& aFileName)
 	{
-	LOG_FUNC
+	OstTraceFunctionEntryExt( CBASETESTCASE_CHECKTREE_ENTRY, this );
 	TInt ret = KErrNone;
 	
 	// flush buffer
@@ -552,34 +606,37 @@
 	TBool isIdentical;
 	if(KErrNone != CompareCurrentTreeToRef(aFileName, isIdentical))
 		{ 
-		RDebug::Printf("CompareCurrentTreeToRef error"); 
+		OstTrace0(TRACE_NORMAL, CBASETESTCASE_CHECKTREE, "CompareCurrentTreeToRef error");
 		ret = KErrGeneral;
 		}	
 	if(!isIdentical)
 		{ 
-		RDebug::Printf("!isIdentical"); 
+		OstTrace0(TRACE_NORMAL, CBASETESTCASE_CHECKTREE_DUP01, "!isIdentical");
 		ret = KErrGeneral;
 		}
+	OstTraceFunctionExitExt( CBASETESTCASE_CHECKTREE_EXIT, this, ret );
 	return ret;
 	}
 	
 	
 TInt CBaseTestCase::ParseConfigDescriptorAndCheckTree(TUsbDeviceDescriptor *devDesc, const TDesC8& configSet, TUint indexTest)
 	{
-	LOG_FUNC
+	OstTraceFunctionEntryExt( CBASETESTCASE_PARSECONFIGDESCRIPTORANDCHECKTREE_ENTRY, this );
 	// Parse config. descriptor
 	TUsbGenericDescriptor* parsed = NULL;
 	TInt err = UsbDescriptorParser::Parse(configSet, parsed);
 	if(err != KErrNone)
 		{
-		RDebug::Printf("parsing error : UsbDescriptorParser::Parse"); 
+		OstTrace0(TRACE_NORMAL, CBASETESTCASE_PARSECONFIGDESCRIPTORANDCHECKTREE, "parsing error : UsbDescriptorParser::Parse");
+		OstTraceFunctionExitExt( CBASETESTCASE_PARSECONFIGDESCRIPTORANDCHECKTREE_EXIT, this, err );
 		return err;
 		}
 	TUsbConfigurationDescriptor* configDesc = TUsbConfigurationDescriptor::Cast(parsed);
 	// checks 
 	if(configDesc == 0)
 		{
-		RDebug::Printf("configDesc == 0");
+		OstTrace0(TRACE_NORMAL, CBASETESTCASE_PARSECONFIGDESCRIPTORANDCHECKTREE_DUP01, "configDesc == 0");
+		OstTraceFunctionExitExt( CBASETESTCASE_PARSECONFIGDESCRIPTORANDCHECKTREE_EXIT_DUP01, this, KErrGeneral );
 		return KErrGeneral; 
 		}
 		
@@ -591,7 +648,7 @@
 	
 TInt CBaseTestCase::CheckTreeAfterDeviceInsertion(CUsbTestDevice& aTestDevice, const TDesC& aFileName)
 	{
-	LOG_FUNC
+	OstTraceFunctionEntryExt( CBASETESTCASE_CHECKTREEAFTERDEVICEINSERTION_ENTRY, this );
 	TUsbGenericDescriptor deviceDesc = aTestDevice.DeviceDescriptor();
 	TUsbGenericDescriptor configDesc = aTestDevice.ConfigurationDescriptor();	
 	return CheckTree(deviceDesc, configDesc, aFileName);