kerneltest/e32test/usbho/t_usbdi/src/TestDeviceBase.cpp
changeset 253 d37db4dcc88d
parent 0 a41df078684a
child 257 3e88ff8f41d5
child 269 d57b86b1867a
--- a/kerneltest/e32test/usbho/t_usbdi/src/TestDeviceBase.cpp	Tue Aug 24 14:42:58 2010 +0100
+++ b/kerneltest/e32test/usbho/t_usbdi/src/TestDeviceBase.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"
@@ -25,6 +25,10 @@
 #include "controltransferrequests.h"
 #include "testinterfacebase.h"
 #include "PBASE-T_USBDI-0486.h"
+#include "OstTraceDefinitions.h"
+#ifdef OST_TRACE_COMPILER_IN_USE
+#include "TestDeviceBaseTraces.h"
+#endif
 #include <e32property.h>
 
 namespace NUnitTesting_USBDI
@@ -37,6 +41,8 @@
 	iConnectTimer(NULL), iWakeupTimer(NULL),
 	iAuxBuffer(NULL)
 	{
+	OstTraceFunctionEntry1( RUSBTESTDEVICE_RUSBTESTDEVICE_ENTRY, this );
+	OstTraceFunctionExit1( RUSBTESTDEVICE_RUSBTESTDEVICE_EXIT, this );
 	}
 	
 RUsbTestDevice::RUsbTestDevice(CBaseTestCase* aTestCase)
@@ -46,25 +52,29 @@
 	iConnectTimer(NULL), iWakeupTimer(NULL),
 	iAuxBuffer(NULL)
 	{
-	LOG_FUNC	
+	OstTraceFunctionEntryExt( RUSBTESTDEVICE_RUSBTESTDEVICE_ENTRY_DUP01, this );
 	iTestCase = aTestCase;
-	RDebug::Printf("iTestCase = %d", iTestCase);
+	OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_RUSBTESTDEVICE, "iTestCase = %d", iTestCase);
+	OstTraceFunctionExit1( RUSBTESTDEVICE_RUSBTESTDEVICE_EXIT_DUP01, this );
 	}
 		
 void RUsbTestDevice::ResetState()
 	{
+	OstTraceFunctionEntry1( RUSBTESTDEVICE_RESETSTATE_ENTRY, this );
 	iCurrentState = EUsbcDeviceStateUndefined;
+	OstTraceFunctionExit1( RUSBTESTDEVICE_RESETSTATE_EXIT, this );
 	}
 
 RUsbTestDevice::~RUsbTestDevice()
 	{
-	LOG_FUNC
+	OstTraceFunctionEntry1( RUSBTESTDEVICE_RUSBTESTDEVICE_ENTRY_DUP02, this );
 	
+	OstTraceFunctionExit1( RUSBTESTDEVICE_RUSBTESTDEVICE_EXIT_DUP02, this );
 	}
 	
 void RUsbTestDevice::Close()
 	{
-	LOG_FUNC
+OstTraceFunctionEntry1( RUSBTESTDEVICE_CLOSE_ENTRY, this );
 
 	delete iWakeupTimer;
 	delete iConnectTimer;
@@ -85,41 +95,44 @@
         TInt r = RProperty::Define(KWordOfDeathCat, KWordOfDeathKey, RProperty::EInt,KAllowAllPolicy, KAllowAllPolicy, 0);
         if(r != KErrNone)
             {
-            RDebug::Print(_L("Could not create the WordOfDeath P&S   (%d)"), r);
+            OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_CLOSE, "Could not create the WordOfDeath P&S   (%d)", r);
             }
-		RDebug::Printf("killing t_usbhost_usbman.exe");
+		OstTrace0(TRACE_NORMAL, RUSBTESTDEVICE_CLOSE_DUP01, "killing t_usbhost_usbman.exe");
         RProperty::Set(KWordOfDeathCat, KWordOfDeathKey, KErrAbort);   // Send the word of death
         User::After(1000000); //allow time for t_usbhost_usbman.exe to clean up
 		}
+	OstTraceFunctionExit1( RUSBTESTDEVICE_CLOSE_EXIT, this );
 	}
 
 
 void RUsbTestDevice::SubscribeToReports(TRequestStatus& aObserverStatus)
 	{
-	LOG_FUNC
+	OstTraceFunctionEntryExt( RUSBTESTDEVICE_SUBSCRIBETOREPORTS_ENTRY, this );
 	
 	// Signal the request as pending
 	
 	iObserverStatus = &aObserverStatus;
 	*iObserverStatus = KRequestPending;
+	OstTraceFunctionExit1( RUSBTESTDEVICE_SUBSCRIBETOREPORTS_EXIT, this );
 	}
 
 
 void RUsbTestDevice::CancelSubscriptionToReports()
 	{
-	LOG_FUNC
+	OstTraceFunctionEntry1( RUSBTESTDEVICE_CANCELSUBSCRIPTIONTOREPORTS_ENTRY, this );
 	
 	// Signal the request as cancelled
 	User::RequestComplete(iObserverStatus,KErrCancel);
+	OstTraceFunctionExit1( RUSBTESTDEVICE_CANCELSUBSCRIPTIONTOREPORTS_EXIT, this );
 	}
 	
 		
 void RUsbTestDevice::OpenL()
 	{
-	LOG_FUNC	
+	OstTraceFunctionEntry1( RUSBTESTDEVICE_OPENL_ENTRY, this );
 	TInt err = KErrNone;
 	
-	RDebug::Printf("starting t_usbhost_usbman.exe");
+	OstTrace0(TRACE_NORMAL, RUSBTESTDEVICE_OPENL, "starting t_usbhost_usbman.exe");
 	TInt r = iOtgUsbMan.Create(_L("t_usbhost_usbman.exe"), _L("client"));
 	gtest(r == KErrNone);
 	iOtgUsbMan.Resume();	
@@ -130,7 +143,7 @@
 	err = iClientDriver.Open(0);
 	if(err != KErrNone)
 		{
-		RDebug::Printf("<Error %d> Unable to open a channel to USB client driver",err);
+		OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_OPENL_DUP01, "<Error %d> Unable to open a channel to USB client driver",err);
 		User::Leave(err);
 		}
 	
@@ -138,7 +151,7 @@
 	err = iClientDriver.DeviceDisconnectFromHost();
 	if(err != KErrNone)
 		{
-		RDebug::Printf("<Error %d> unable to disconnect device from host",err);
+		OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_OPENL_DUP02, "<Error %d> unable to disconnect device from host",err);
 		User::Leave(err);
 		}
 	
@@ -156,28 +169,29 @@
 	_LIT8(KYes, "yes");
 	_LIT8(KNo, "no");
 	User::LeaveIfError(iClientDriver.DeviceCaps(iDeviceCaps));
- 	RDebug::Printf("------ USB device capabilities -------");
-	RDebug::Printf("Number of endpoints:                %d",iDeviceCaps().iTotalEndpoints);	
-	RDebug::Printf("Supports Software-Connect:          %S",iDeviceCaps().iConnect ? &KYes() : &KNo());
-	RDebug::Printf("Device is Self-Powered:             %S",iDeviceCaps().iSelfPowered ? &KYes() : &KNo());
-	RDebug::Printf("Supports Remote-Wakeup:             %S",iDeviceCaps().iRemoteWakeup ? &KYes() : &KNo());
-	RDebug::Printf("Supports High-speed:                %S",iDeviceCaps().iHighSpeed ? &KYes() : &KNo());
-	RDebug::Printf("Supports unpowered cable detection: %S",(iDeviceCaps().iFeatureWord1 & KUsbDevCapsFeatureWord1_CableDetectWithoutPower) ? &KYes() : &KNo());
-	RDebug::Printf("--------------------------------------");
+ 	OstTrace0(TRACE_NORMAL, RUSBTESTDEVICE_OPENL_DUP03, "------ USB device capabilities -------");
+	OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_OPENL_DUP04, "Number of endpoints:                %d",iDeviceCaps().iTotalEndpoints);	
+	OstTraceExt1(TRACE_NORMAL, RUSBTESTDEVICE_OPENL_DUP05, "Supports Software-Connect:          %s",iDeviceCaps().iConnect ? KYes() : KNo());
+	OstTraceExt1(TRACE_NORMAL, RUSBTESTDEVICE_OPENL_DUP06, "Device is Self-Powered:             %S",iDeviceCaps().iSelfPowered ? KYes() : KNo());
+	OstTraceExt1(TRACE_NORMAL, RUSBTESTDEVICE_OPENL_DUP07, "Supports Remote-Wakeup:             %S",iDeviceCaps().iRemoteWakeup ? KYes() : KNo());
+	OstTraceExt1(TRACE_NORMAL, RUSBTESTDEVICE_OPENL_DUP08, "Supports High-speed:                %S",iDeviceCaps().iHighSpeed ? KYes() : KNo());
+	OstTraceExt1(TRACE_NORMAL, RUSBTESTDEVICE_OPENL_DUP09, "Supports unpowered cable detection: %S",(iDeviceCaps().iFeatureWord1 & KUsbDevCapsFeatureWord1_CableDetectWithoutPower) ? KYes() : KNo());
+	OstTrace0(TRACE_NORMAL, RUSBTESTDEVICE_OPENL_DUP10, "--------------------------------------");
 	
+	OstTraceFunctionExit1( RUSBTESTDEVICE_OPENL_EXIT, this );
 	}
 
 
 TInt RUsbTestDevice::SetClassCode(TUint8 aClassCode,TUint8 aSubClassCode,TUint8 aDeviceProtocol)
 	{
-	LOG_FUNC
+    OstTraceFunctionEntryExt( RUSBTESTDEVICE_SETCLASSCODE_ENTRY, this );
 
 	// Get Device descriptor
 	TBuf8<KUsbDescSize_Device> deviceDescriptor;
 	TInt err(iClientDriver.GetDeviceDescriptor(deviceDescriptor));
 	if(err != KErrNone)
 		{
-		RDebug::Printf("<Error %d> Unable to obtain device descriptor",err);
+		OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_SETCLASSCODE, "<Error %d> Unable to obtain device descriptor",err);
 		}
 	else
 		{
@@ -188,23 +202,24 @@
 		err = iClientDriver.SetDeviceDescriptor(deviceDescriptor);
 		if(err != KErrNone)
 			{
-			RDebug::Printf("<Error %d> Unable to set the device dsecriptor",err);
+			OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_SETCLASSCODE_DUP01, "<Error %d> Unable to set the device dsecriptor",err);
 			}
 		}
+	OstTraceFunctionExitExt( RUSBTESTDEVICE_SETCLASSCODE_EXIT, this, err );
 	return err;
 	}
 
 
 TInt RUsbTestDevice::SetUsbSpecification(TUint16 aSpecification)
 	{
-	LOG_FUNC
+    OstTraceFunctionEntryExt( RUSBTESTDEVICE_SETUSBSPECIFICATION_ENTRY, this );
 
 	// Get Device descriptor
 	TBuf8<KUsbDescSize_Device> deviceDescriptor;
 	TInt err(iClientDriver.GetDeviceDescriptor(deviceDescriptor));
 	if(err != KErrNone)
 		{
-		RDebug::Printf("<Error %d> Unable to obtain device descriptor",err);
+		OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_SETUSBSPECIFICATION, "<Error %d> Unable to obtain device descriptor",err);
 		}
 	else
 		{
@@ -221,23 +236,24 @@
 		err = iClientDriver.SetDeviceDescriptor(deviceDescriptor);
 		if(err != KErrNone)
 			{
-			RDebug::Printf("<Error %d> Unable to set the device dsecriptor",err);
+			OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_SETUSBSPECIFICATION_DUP01, "<Error %d> Unable to set the device dsecriptor",err);
 			}
 		}
+	OstTraceFunctionExitExt( RUSBTESTDEVICE_SETUSBSPECIFICATION_EXIT, this, err );
 	return err;
 	}
 
 
 TInt RUsbTestDevice::SetVendor(TUint16 aVendorId)
 	{
-	LOG_FUNC
+    OstTraceFunctionEntryExt( RUSBTESTDEVICE_SETVENDOR_ENTRY, this );
 
 	// Get Device descriptor
 	TBuf8<KUsbDescSize_Device> deviceDescriptor;
 	TInt err(iClientDriver.GetDeviceDescriptor(deviceDescriptor));
 	if(err != KErrNone)
 		{
-		RDebug::Printf("<Error %d> Unable to obtain device descriptor",err);
+		OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_SETVENDOR, "<Error %d> Unable to obtain device descriptor",err);
 		}
 	else
 		{
@@ -249,9 +265,10 @@
 		err = iClientDriver.SetDeviceDescriptor(deviceDescriptor);
 		if(err != KErrNone)
 			{
-			RDebug::Printf("<Error %d> Unable to set the device descriptor",err);
+			OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_SETVENDOR_DUP01, "<Error %d> Unable to set the device descriptor",err);
 			}
 		}
+	OstTraceFunctionExitExt( RUSBTESTDEVICE_SETVENDOR_EXIT, this, err );
 	return err;
 	}
 
@@ -259,14 +276,14 @@
 TInt RUsbTestDevice::SetProduct(TUint16 aProductId,const TDesC16& aProductString,
 				const TDesC16& aManufacturerString,const TDesC16& aSerialNumberString)
 	{
-	LOG_FUNC
+    OstTraceFunctionEntryExt( RUSBTESTDEVICE_SETPRODUCT_ENTRY, this );
 
 	// Get Device descriptor
 	TBuf8<KUsbDescSize_Device> deviceDescriptor;
 	TInt err(iClientDriver.GetDeviceDescriptor(deviceDescriptor));
 	if(err != KErrNone)
 		{
-		RDebug::Printf("<Error %d> Unable to obtain device descriptor",err);
+		OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_SETPRODUCT, "<Error %d> Unable to obtain device descriptor",err);
 		}
 	else
 		{
@@ -278,17 +295,19 @@
 		err = iClientDriver.SetDeviceDescriptor(deviceDescriptor);
 		if(err != KErrNone)
 			{
-			RDebug::Printf("<Error %d> Unable to set the device dsecriptor",err);
+			OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_SETPRODUCT_DUP01, "<Error %d> Unable to set the device dsecriptor",err);
+			OstTraceFunctionExitExt( RUSBTESTDEVICE_SETPRODUCT_EXIT, this, err );
 			return err;
 			}
 		
-		RDebug::Printf("Product Identity set");
+		OstTrace0(TRACE_NORMAL, RUSBTESTDEVICE_SETPRODUCT_DUP02, "Product Identity set");
 	
 		// Product string
 		err = iClientDriver.SetProductStringDescriptor(aProductString);
 		if(err != KErrNone)
 			{
-			RDebug::Printf("<Error %d> Unable to set product string descriptor",err);
+			OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_SETPRODUCT_DUP03, "<Error %d> Unable to set product string descriptor",err);
+			OstTraceFunctionExitExt( RUSBTESTDEVICE_SETPRODUCT_EXIT_DUP01, this, err );
 			return err;
 			}
 
@@ -296,7 +315,8 @@
 		err = iClientDriver.SetManufacturerStringDescriptor(aManufacturerString);
 		if(err != KErrNone)
 			{
-			RDebug::Printf("<Error %d> Unable to set the manufacturer string descriptor",err);
+			OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_SETPRODUCT_DUP04, "<Error %d> Unable to set the manufacturer string descriptor",err);
+			OstTraceFunctionExitExt( RUSBTESTDEVICE_SETPRODUCT_EXIT_DUP02, this, err );
 			return err;
 			}
 	
@@ -304,55 +324,61 @@
 		err = iClientDriver.SetSerialNumberStringDescriptor(aSerialNumberString);
 		if(err != KErrNone)
 			{
-			RDebug::Printf("<Error %d> Unable to set the serial number string descriptor",err);
+			OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_SETPRODUCT_DUP05, "<Error %d> Unable to set the serial number string descriptor",err);
+			OstTraceFunctionExitExt( RUSBTESTDEVICE_SETPRODUCT_EXIT_DUP03, this, err );
 			return err;
 			}
 		}
+	OstTraceFunctionExitExt( RUSBTESTDEVICE_SETPRODUCT_EXIT_DUP04, this, KErrNone );
 	return KErrNone;
 	}
 
 
 TInt RUsbTestDevice::SetConfigurationString(const TDesC16& aConfigString)
 	{
-	LOG_FUNC
+    OstTraceFunctionEntryExt( RUSBTESTDEVICE_SETCONFIGURATIONSTRING_ENTRY, this );
 
 	TInt err(iClientDriver.SetConfigurationStringDescriptor(aConfigString));
 	if(err != KErrNone)
 		{
-		RDebug::Printf("<Error %d> Unable to set configuration string descriptor",err);
+		OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_SETCONFIGURATIONSTRING, "<Error %d> Unable to set configuration string descriptor",err);
 		}
+	OstTraceFunctionExitExt( RUSBTESTDEVICE_SETCONFIGURATIONSTRING_EXIT, this, err );
 	return err;
 	}
 
 
 void RUsbTestDevice::AddInterface(CInterfaceBase* aInterface)
 	{
-	LOG_FUNC
+	OstTraceFunctionEntryExt( RUSBTESTDEVICE_ADDINTERFACE_ENTRY, this );
 		
 	// Add the interface to the device
 	TInt err = iInterfaces.Append(aInterface);
 	
 	if(err != KErrNone)
 		{
-		RDebug::Printf("<Error %d> Unable to add interface",err);
+		OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_ADDINTERFACE, "<Error %d> Unable to add interface",err);
 		return ReportError(err);
 		}
+	OstTraceFunctionExit1( RUSBTESTDEVICE_ADDINTERFACE_EXIT, this );
 	}
 
 
 CInterfaceBase& RUsbTestDevice::Interface(TInt aIndex)
 	{
+	OstTraceFunctionEntryExt( RUSBTESTDEVICE_INTERFACE_ENTRY, this );
+	OstTraceFunctionExit1( RUSBTESTDEVICE_INTERFACE_EXIT, this );
 	return *iInterfaces[aIndex];
 	}
 
 
 void RUsbTestDevice::SoftwareConnect()
 	{
-	LOG_FUNC
+	OstTraceFunctionEntry1( RUSBTESTDEVICE_SOFTWARECONNECT_ENTRY, this );
 	TInt err(iClientDriver.PowerUpUdc());
 	if((err != KErrNone) && (err != KErrNotReady))
 		{
-		RDebug::Printf("<Error %d> Power Up Udc",err);
+		OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_SOFTWARECONNECT, "<Error %d> Power Up Udc",err);
 		ReportError(err);
 		}
 		
@@ -361,60 +387,63 @@
 		err = iClientDriver.DeviceConnectToHost();
 		if(err != KErrNone)
 			{
-			RDebug::Printf("<Error %d> Unable to connect to the host",err);
+			OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_SOFTWARECONNECT_DUP01, "<Error %d> Unable to connect to the host",err);
 			ReportError(err);
 			}
 		}
 	else
 		{
-		RDebug::Printf("Please connect device to Host");
+		OstTrace0(TRACE_NORMAL, RUSBTESTDEVICE_SOFTWARECONNECT_DUP02, "Please connect device to Host");
 		}	
+	OstTraceFunctionExit1( RUSBTESTDEVICE_SOFTWARECONNECT_EXIT, this );
 	}   	
 	 
 void RUsbTestDevice::SoftwareDisconnect()
 	{
-	LOG_FUNC
+	OstTraceFunctionEntry1( RUSBTESTDEVICE_SOFTWAREDISCONNECT_ENTRY, this );
 	
 	if(iDeviceCaps().iConnect) 
 		{
 		TInt err(iClientDriver.DeviceDisconnectFromHost());
 		if(err != KErrNone)
 			{
-			RDebug::Printf("<Error %d> Unable to disconnect from the host",err);
+			OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_SOFTWAREDISCONNECT, "<Error %d> Unable to disconnect from the host",err);
 			ReportError(err);
 			}
 		}
 	else
 		{
-		RDebug::Printf("Please disconnect device from Host");
+		OstTrace0(TRACE_NORMAL, RUSBTESTDEVICE_SOFTWAREDISCONNECT_DUP01, "Please disconnect device from Host");
 		}
 		
+	OstTraceFunctionExit1( RUSBTESTDEVICE_SOFTWAREDISCONNECT_EXIT, this );
 	}       
 
 
 void RUsbTestDevice::RemoteWakeup()
 	{
-	LOG_FUNC
+	OstTraceFunctionEntry1( RUSBTESTDEVICE_REMOTEWAKEUP_ENTRY, this );
 	if(iDeviceCaps().iConnect) 
 		{
 		TInt err(iClientDriver.SignalRemoteWakeup());
 		if(err != KErrNone)
 			{
-			RDebug::Printf("<Error %d> Unable to perform a remote wakeup",err);
+			OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_REMOTEWAKEUP, "<Error %d> Unable to perform a remote wakeup",err);
 			ReportError(err);
 			}
 		}
 	else
 		{
-		RDebug::Printf("remote wakeup not supported");
+		OstTrace0(TRACE_NORMAL, RUSBTESTDEVICE_REMOTEWAKEUP_DUP01, "remote wakeup not supported");
 		}
+	OstTraceFunctionExit1( RUSBTESTDEVICE_REMOTEWAKEUP_EXIT, this );
 	}
 
 
 TInt RUsbTestDevice::ProcessRequestL(TUint8 aRequest,TUint16 aValue,TUint16 aIndex,
 	TUint16 aDataReqLength,const TDesC8& aPayload)
 	{
-	LOG_FUNC
+	OstTraceFunctionEntryExt( RUSBTESTDEVICE_PROCESSREQUESTL_ENTRY, this );
 	
 	if(aRequest == KVendorEmptyRequest)
 		{
@@ -431,7 +460,7 @@
 		}
 	else if(aRequest == KVendorDisconnectDeviceAThenConnectDeviceCRequest)
 		{
-		RDebug::Printf("**aRequest == KVendorDisconnectDeviceAThenConnectDeviceCRequest, this = 0x%08x", this);
+		OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_PROCESSREQUESTL, "**aRequest == KVendorDisconnectDeviceAThenConnectDeviceCRequest, this = 0x%08x", this);
 		// Handle a reconnect requests from the host		
 		AcknowledgeRequestReceived();			
 		
@@ -445,11 +474,12 @@
 		iTestCaseT_USBDI_0486->TestDeviceC()->OpenL(KTestDeviceC_SN);		
 		// Connect the device to the host	
 		iTestCaseT_USBDI_0486->TestDeviceC()->SoftwareConnect();
+		OstTraceFunctionExitExt( RUSBTESTDEVICE_PROCESSREQUESTL_EXIT, this, KErrAbort );
 		return KErrAbort;
 		}
 	else if(aRequest == KVendorDisconnectDeviceCThenConnectDeviceARequest)
 		{
-		RDebug::Printf("**aRequest == KVendorDisconnectDeviceCThenConnectDeviceARequest, this = 0x%08x", this);
+		OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_PROCESSREQUESTL_DUP01, "**aRequest == KVendorDisconnectDeviceCThenConnectDeviceARequest, this = 0x%08x", this);
 		// Handle a reconnect requests from the host		
 		AcknowledgeRequestReceived();		
 		 
@@ -468,6 +498,7 @@
 		
 		// Connect the device to the host	
 		iTestCaseT_USBDI_0486->TestDeviceD()->SoftwareConnect();	
+		OstTraceFunctionExitExt( RUSBTESTDEVICE_PROCESSREQUESTL_EXIT_DUP01, this, KErrAbort );
 		return KErrAbort;
 		}		
 	else if(aRequest == KVendorTestCasePassed)
@@ -487,7 +518,7 @@
 		
 		HBufC16* msg = HBufC16::NewL(aPayload.Length());
 		msg->Des().Copy(aPayload);
-		RDebug::Printf("<Host> Test case failed: %S",msg);
+		OstTraceExt1(TRACE_NORMAL, RUSBTESTDEVICE_PROCESSREQUESTL_DUP02, "<Host> Test case failed: %S",*msg);
 		delete msg;
 		msg = 0;
 		ReportError(-aValue);
@@ -504,10 +535,10 @@
 		// Handle a payload request from the host
 
 		AcknowledgeRequestReceived();
-		RDebug::Printf("Put payload");
+		OstTrace0(TRACE_NORMAL, RUSBTESTDEVICE_PROCESSREQUESTL_DUP03, "Put payload");
 		if(aPayload.Compare(_L8("DEADBEEF")) != 0)
 			{
-			RDebug::Printf("<Error %d> Payload not as expected",KErrCorrupt);
+			OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_PROCESSREQUESTL_DUP04, "<Error %d> Payload not as expected",KErrCorrupt);
 			ReportError(KErrCorrupt);
 			}
 		}
@@ -515,45 +546,46 @@
 		{
 		// Handle a payload request to the host
 
-		RDebug::Printf("Get payload");
+		OstTrace0(TRACE_NORMAL, RUSBTESTDEVICE_PROCESSREQUESTL_DUP05, "Get payload");
 		__ASSERT_DEBUG(iAuxBuffer, User::Panic(_L("Trying to write non-allocated buffer"), KErrGeneral));
-		RDebug::Printf("iAuxBuffer = ....");
-		RDebug::RawPrint(*iAuxBuffer);
-		RDebug::Printf("\n");
+		OstTrace0(TRACE_NORMAL, RUSBTESTDEVICE_PROCESSREQUESTL_DUP06, "iAuxBuffer = ....");
+        OstTraceData(TRACE_NORMAL, RUSBTESTDEVICE_PROCESSREQUESTL_DUP56, "", iAuxBuffer->Ptr(), iAuxBuffer->Length());
+		OstTrace0(TRACE_NORMAL, RUSBTESTDEVICE_PROCESSREQUESTL_DUP07, "\n");
 		
 		//Perform synchronous write to EP0
 		//This allows the subsequent 'Read' request to
 		//take place
 		TInt ret = iDeviceEp0->SendDataSynchronous(*iAuxBuffer);
-		RDebug::Printf("Write (from device callback) executed with error %d", ret);
+		OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_PROCESSREQUESTL_DUP08, "Write (from device callback) executed with error %d", ret);
 		}
 	else if(aRequest == KVendorUnrespondRequest)
 		{
 		// Do not acknowledge this request
 		
-		RDebug::Printf("Unrespond request: continually NAK the host");
+		OstTrace0(TRACE_NORMAL, RUSBTESTDEVICE_PROCESSREQUESTL_DUP09, "Unrespond request: continually NAK the host");
 		}
 	else if(aRequest == KVendorStallRequest)
 		{
 		// Stall the specified endpoint
 		
 		AcknowledgeRequestReceived();
-		RDebug::Printf("Stalling endpoint %d",aValue);
+		OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_PROCESSREQUESTL_DUP10, "Stalling endpoint %d",aValue);
 						
 		}
 	else
 		{
 		// Maybe forward to derived classes
 		}
+	OstTraceFunctionExitExt( RUSBTESTDEVICE_PROCESSREQUESTL_EXIT_DUP02, this, KErrNone );
 	return KErrNone;
 	}
 
 
 void RUsbTestDevice::StateChangeL(TUsbcDeviceState aNewState,TInt aChangeCompletionCode)
 	{
-	LOG_FUNC
+	OstTraceFunctionEntryExt( RUSBTESTDEVICE_STATECHANGEL_ENTRY, this );
 	
-	RDebug::Printf("Client state change to %d err=%d",aNewState,aChangeCompletionCode);
+	OstTraceExt2(TRACE_NORMAL, RUSBTESTDEVICE_STATECHANGEL, "Client state change to %d err=%d",aNewState,aChangeCompletionCode);
 	
 	// Notify the test case of failed state change notification
 	
@@ -577,7 +609,7 @@
 			// The is a state change from EUsbcDeviceStateConfigured to aNewState
 			// so stop reading from control ep0
 			
-			RDebug::Printf("Ignoring control ep0");
+			OstTrace0(TRACE_NORMAL, RUSBTESTDEVICE_STATECHANGEL_DUP01, "Ignoring control ep0");
 			
 			// Stop reading ep0 directed requests
 			
@@ -597,7 +629,7 @@
 			// Device has now been placed into a fully configured state by the host
 			// so start reading from control ep0
 			
-			RDebug::Printf("Reading from control ep0");
+			OstTrace0(TRACE_NORMAL, RUSBTESTDEVICE_STATECHANGEL_DUP02, "Reading from control ep0");
 			
 			// Start reading ep0 directed requests
 			
@@ -618,12 +650,13 @@
 	// Forward the state change notification to derived classes
 	
 	OnStateChangeL(aNewState);
+	OstTraceFunctionExit1( RUSBTESTDEVICE_STATECHANGEL_EXIT, this );
 	}
 	
 
 void RUsbTestDevice::StartEp0Reading()
 	{
-	LOG_FUNC
+    OstTraceFunctionEntry1( RUSBTESTDEVICE_STARTEP0READING_ENTRY, this );
 
 	// Start reading device directed ep0 requests
 	
@@ -640,12 +673,13 @@
 		{
 		iInterfaces[i]->StartEp0Reading();
 		}
+	OstTraceFunctionExit1( RUSBTESTDEVICE_STARTEP0READING_EXIT, this );
 	}
 
 
 void RUsbTestDevice::StopEp0Reading()
 	{
-	LOG_FUNC
+    OstTraceFunctionEntry1( RUSBTESTDEVICE_STOPEP0READING_ENTRY, this );
 
 	// Stop reading interface directed requests
 	
@@ -662,33 +696,36 @@
 		{
 		return ReportError(err);
 		}
+	OstTraceFunctionExit1( RUSBTESTDEVICE_STOPEP0READING_EXIT, this );
 	}
 
 
 void RUsbTestDevice::AcknowledgeRequestReceived()
 	{
-	LOG_FUNC
+	OstTraceFunctionEntry1( RUSBTESTDEVICE_ACKNOWLEDGEREQUESTRECEIVED_ENTRY, this );
 	
 	TInt err(iDeviceEp0->Reader().Acknowledge());
-	RDebug::Printf("err = %d",err);
+	OstTrace1(TRACE_NORMAL, RUSBTESTDEVICE_ACKNOWLEDGEREQUESTRECEIVED, "err = %d",err);
 	if(err != KErrNone)
 		{
 		ReportError(err);
 		}
+	OstTraceFunctionExit1( RUSBTESTDEVICE_ACKNOWLEDGEREQUESTRECEIVED_EXIT, this );
 	}
 
 
 
 void RUsbTestDevice::ReportError(TInt aCompletionCode)
 	{
-	LOG_FUNC
-	RDebug::Printf("err or aCompletionCode = %d, observer status = %d, KRequestPending = %d",
+	OstTraceFunctionEntryExt( RUSBTESTDEVICE_REPORTERROR_ENTRY, this );
+	OstTraceExt3(TRACE_NORMAL, RUSBTESTDEVICE_REPORTERROR, "err or aCompletionCode = %d, observer status = %d, KRequestPending = %d",
 			aCompletionCode, iObserverStatus->Int(), KRequestPending);
 	if(*iObserverStatus == KRequestPending)
 		{
-		RDebug::Printf("In complete request");
+		OstTrace0(TRACE_NORMAL, RUSBTESTDEVICE_REPORTERROR_DUP01, "In complete request");
 		User::RequestComplete(iObserverStatus,aCompletionCode);
 		}
+	OstTraceFunctionExit1( RUSBTESTDEVICE_REPORTERROR_EXIT, this );
 	}