kerneltest/e32test/usbho/t_usbdi/src/PBASE-T_USBDI-1229.cpp
changeset 259 57b9594f5772
parent 0 a41df078684a
child 257 3e88ff8f41d5
--- a/kerneltest/e32test/usbho/t_usbdi/src/PBASE-T_USBDI-1229.cpp	Wed Aug 18 11:08:29 2010 +0300
+++ b/kerneltest/e32test/usbho/t_usbdi/src/PBASE-T_USBDI-1229.cpp	Thu Sep 02 21:54:16 2010 +0300
@@ -1,4 +1,4 @@
-// Copyright (c) 2008-2009 Nokia Corporation and/or its subsidiary(-ies).
+// Copyright (c) 2008-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"
@@ -20,6 +20,10 @@
 #include "testpolicy.h"
 #include "modelleddevices.h"
 #include "testliterals.h"
+#include "OstTraceDefinitions.h"
+#ifdef OST_TRACE_COMPILER_IN_USE
+#include "PBASE-T_USBDI-1229Traces.h"
+#endif
 
 
  
@@ -56,10 +60,12 @@
 
 CUT_PBASE_T_USBDI_1229* CUT_PBASE_T_USBDI_1229::NewL(TBool aHostRole)
 	{
+	OstTraceFunctionEntry1( CUT_PBASE_T_USBDI_1229_NEWL_ENTRY, aHostRole );
 	CUT_PBASE_T_USBDI_1229* self = new (ELeave) CUT_PBASE_T_USBDI_1229(aHostRole);
 	CleanupStack::PushL(self);
 	self->ConstructL();
 	CleanupStack::Pop(self);
+	OstTraceFunctionExit1( CUT_PBASE_T_USBDI_1229_NEWL_EXIT, ( TUint )( self ) );
 	return self;
 	}
 	
@@ -68,11 +74,14 @@
 :	CBaseBulkTestCase(KTestCaseId,aHostRole),
 	iCaseStep(EInProgress)
 	{
+	OstTraceFunctionEntryExt( CUT_PBASE_T_USBDI_1229_CUT_PBASE_T_USBDI_1229_ENTRY, this );
+	OstTraceFunctionExit1( CUT_PBASE_T_USBDI_1229_CUT_PBASE_T_USBDI_1229_EXIT, this );
 	} 
 
 
 void CUT_PBASE_T_USBDI_1229::ConstructL()
 	{
+	OstTraceFunctionEntry1( CUT_PBASE_T_USBDI_1229_CONSTRUCTL_ENTRY, this );
 	BaseBulkConstructL();
 
 	iInBuffer = HBufC8::NewL(KTestBufferLength);
@@ -92,39 +101,42 @@
 		iOutBufferPtr.Append(KLiteralEnglish5());
 		}
 
-	RDebug::Printf("CUT_PBASE_T_USBDI_1229::ConstructL(): buffer created");
+	OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_CONSTRUCTL, "CUT_PBASE_T_USBDI_1229::ConstructL(): buffer created");
+	OstTraceFunctionExit1( CUT_PBASE_T_USBDI_1229_CONSTRUCTL_EXIT, this );
 	}
 
 
 CUT_PBASE_T_USBDI_1229::~CUT_PBASE_T_USBDI_1229()
 	{
-	LOG_FUNC
+	OstTraceFunctionEntry1( CUT_PBASE_T_USBDI_1229_CUT_PBASE_T_USBDI_1229_ENTRY_DUP01, this );
+	OstTraceFunctionExit1( CUT_PBASE_T_USBDI_1229_CUT_PBASE_T_USBDI_1229_EXIT_DUP01, this );
 	}
 	
 void CUT_PBASE_T_USBDI_1229::KillTransfers()
 	{
-	LOG_FUNC
+	OstTraceFunctionEntry1( CUT_PBASE_T_USBDI_1229_KILLTRANSFERS_ENTRY, this );
 	
 	iOutTransfer[0]->Cancel();
 	iOutTransfer[1]->Cancel();
+	OstTraceFunctionExit1( CUT_PBASE_T_USBDI_1229_KILLTRANSFERS_EXIT, this );
 	}
 
 void CUT_PBASE_T_USBDI_1229::ExtractDeviceReadBytes()
 	{
-	LOG_FUNC
+	OstTraceFunctionEntry1( CUT_PBASE_T_USBDI_1229_EXTRACTDEVICEREADBYTES_ENTRY, this );
 	
 	iControlEp0->LastRequestCompletionTime( iEndTime[KTestTimer]);
 	iTimingError = iTimingError == KErrNone ? CheckTimes(KBaseTimer, KTestTimer, KMaxTimeDiffPercentage) : iTimingError;
 	ResetTimes(KTestTimer);
 	
-	RDebug::Printf("Collect client's return of the number of bytes read on its bulk out endpoint ...");
+	OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EXTRACTDEVICEREADBYTES, "Collect client's return of the number of bytes read on its bulk out endpoint ...");
 	TLex8 lex(iInBufferPtr.Left(KNumberStringLength));
 	TUint32 numBytes = 0;
 	User::LeaveIfError(lex.Val(numBytes, EDecimal));
-	RDebug::Printf("********************NUM*BYTES****************************");
-	RDebug::Printf("         NUM BYTES READ BY CLIENT ==== %d ====           ", numBytes);
-	RDebug::Printf("********************NUM*BYTES****************************");
-	RDebug::Printf("\n");
+	OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EXTRACTDEVICEREADBYTES_DUP01, "********************NUM*BYTES****************************");
+	OstTrace1(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EXTRACTDEVICEREADBYTES_DUP02, "         NUM BYTES READ BY CLIENT ==== %d ====           ", numBytes);
+	OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EXTRACTDEVICEREADBYTES_DUP03, "********************NUM*BYTES****************************");
+	OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EXTRACTDEVICEREADBYTES_DUP04, "\n");
 
 	if(numBytes != 0)
 		//Do not count this case - it may result from the remote resetting when all bulk transfers have completed
@@ -134,11 +146,13 @@
 		iDeviceMinTimedNumBytesRead = numBytesSinceLast < iDeviceMinTimedNumBytesRead ?  numBytesSinceLast : iDeviceMinTimedNumBytesRead ;
 		iDeviceMaxTimedNumBytesRead = numBytesSinceLast > iDeviceMaxTimedNumBytesRead ?  numBytesSinceLast : iDeviceMaxTimedNumBytesRead ;;
 		}
+	OstTraceFunctionExit1( CUT_PBASE_T_USBDI_1229_EXTRACTDEVICEREADBYTES_EXIT, this );
 	}
 
 
 void CUT_PBASE_T_USBDI_1229::PostTransferAction()
 	{
+	OstTraceFunctionEntry1( CUT_PBASE_T_USBDI_1229_POSTTRANSFERACTION_ENTRY, this );
 	switch(iTransferResult)
 		{
 		case KErrNone:
@@ -148,20 +162,22 @@
 		case KTransferSuccess:
 			//indicates data validation failure
 			{
-			RDebug::Printf("Asking client to post validation recorded on the endpoint on its interface - ready for collection");
+			OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_POSTTRANSFERACTION, "Asking client to post validation recorded on the endpoint on its interface - ready for collection");
 			iCaseStep = ERequestPrepareEndpointValidationResult;
 			TRecordedValidationResultRequest request(1,1);
 			iControlEp0->SendRequest(request,this);
 			}
+			OstTraceFunctionExit1( CUT_PBASE_T_USBDI_1229_POSTTRANSFERACTION_EXIT, this );
 			return;
 		
 		default:
 			{
 			iCaseStep = EFailed;
-			RDebug::Print(iMsg);
+			OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_POSTTRANSFERACTION_DUP01, iMsg);
 			TTestCaseFailed request(iTransferResult,iMsg);
 			iControlEp0->SendRequest(request,this);
 			}
+			OstTraceFunctionExit1( CUT_PBASE_T_USBDI_1229_POSTTRANSFERACTION_EXIT_DUP01, this );
 			return;
 		}
 	}
@@ -169,11 +185,12 @@
 
 TBool CUT_PBASE_T_USBDI_1229::PerformNextTransfer(TInt aTransferId)
 	{
-	LOG_FUNC
+	OstTraceFunctionEntryExt( CUT_PBASE_T_USBDI_1229_PERFORMNEXTTRANSFER_ENTRY, this );
 	
 	if(iNumWriteBytesRequested >= KTotalBytesToTransfer)
 		{
-		RDebug::Printf("All transfers sent - num bytes actually written = %d, num bytes required to be written = %d", iNumWriteBytesRequested, KTotalBytesToTransfer);
+		OstTraceExt2(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_PERFORMNEXTTRANSFER, "All transfers sent - num bytes actually written = %u, num bytes required to be written = %u", iNumWriteBytesRequested, KTotalBytesToTransfer);
+		OstTraceFunctionExitExt( CUT_PBASE_T_USBDI_1229_PERFORMNEXTTRANSFER_EXIT, this, EFalse );
 		return EFalse; //Not writing any more - signal to user that no more transfers are required
 		}
 	TUint bytesToWrite = KTotalBytesToTransfer - iNumWriteBytesRequested;
@@ -185,32 +202,35 @@
 	bulkTransfer.TransferOut(iOutBufferPtr.Mid(iNumWriteBytesRequested%(KLiteralEnglish5().Length()), numWriteBytes), EFalse);
 	iNumWriteBytesRequested += numWriteBytes;
 
+	OstTraceFunctionExitExt( CUT_PBASE_T_USBDI_1229_PERFORMNEXTTRANSFER_EXIT_DUP01, this, ETrue );
 	return ETrue;
 	}
 
 	
 void CUT_PBASE_T_USBDI_1229::RequestNumBytesSent(TUint8 aTimerIndex)
 	{
+	OstTraceFunctionEntryExt( CUT_PBASE_T_USBDI_1229_REQUESTNUMBYTESSENT_ENTRY, this );
 	iInBufferPtr.Set(iInBuffer->Des());
 	iInBufferPtr.Zero(); //reset
 	iInBufferPtr.SetLength(KNumberStringLength);
 	TInterfaceGetRecordedNumBytesReadInPayload request(1,1,iInBufferPtr);
 	iControlEp0->SendRequest(request,this);
 	iControlEp0->LastRequestStartTime( iStartTime[aTimerIndex]);
+	OstTraceFunctionExit1( CUT_PBASE_T_USBDI_1229_REQUESTNUMBYTESSENT_EXIT, this );
 	}
 
 
 void CUT_PBASE_T_USBDI_1229::Ep0TransferCompleteL(TInt aCompletionCode)
 	{
-	LOG_FUNC
+	OstTraceFunctionEntryExt( CUT_PBASE_T_USBDI_1229_EP0TRANSFERCOMPLETEL_ENTRY, this );
 	
-	RDebug::Printf("Ep0TransferCompleteL with aCompletionCode = %d, test step = %d", aCompletionCode, iCaseStep);
+	OstTraceExt2(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EP0TRANSFERCOMPLETEL, "Ep0TransferCompleteL with aCompletionCode = %d, test step = %d", aCompletionCode, iCaseStep);
 	
 	if(aCompletionCode != KErrNone)
 		{
 		if(iCaseStep == EFailed)
 			{// ignore error, nad catch the TestFailed method called further down.
-			RDebug::Printf("***Failure sending FAIL message to client on endpoint 0***");
+			OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EP0TRANSFERCOMPLETEL_DUP01, "***Failure sending FAIL message to client on endpoint 0***");
 			}
 		else
 			{
@@ -218,10 +238,11 @@
 			KillTransfers();
 			_LIT(lit, "<Error %d> Transfer to control endpoint 0 was not successful");
 			msg.Format(lit,aCompletionCode);
-			RDebug::Print(msg);
+			OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EP0TRANSFERCOMPLETEL_DUP02, msg);
 			iCaseStep = EFailed;
 			TTestCaseFailed request(aCompletionCode,msg);
 			iControlEp0->SendRequest(request,this);
+			OstTraceFunctionExit1( CUT_PBASE_T_USBDI_1229_EP0TRANSFERCOMPLETEL_EXIT, this );
 			return;
 			}
 		}
@@ -241,7 +262,7 @@
 		case EGetTimerBase:
 			{
 			iControlEp0->LastRequestCompletionTime( iEndTime[KBaseTimer]);
-			RDebug::Printf("Asking client for continuous 'Read' and 'Validate'");
+			OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EP0TRANSFERCOMPLETEL_DUP03, "Asking client for continuous 'Read' and 'Validate'");
 			iCaseStep = ERequestRepeatedReadAndValidate;
 			TRepeatedReadAndValidateDataRequest request(1,1,KLiteralEnglish5(),KDeviceNumReadBytes,KTotalBytesToTransfer);// EP2 means endpoint index 2 not the actual endpoint number, here the ep with 32 byte max packet size
 			iControlEp0->SendRequest(request,this);
@@ -250,7 +271,7 @@
 			
 		case ERequestRepeatedReadAndValidate:
 			{
-			RDebug::Printf("Try to perform ALL transfers");
+			OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EP0TRANSFERCOMPLETEL_DUP04, "Try to perform ALL transfers");
 	
 			iCaseStep = ETransfer;	
 			
@@ -278,7 +299,7 @@
 			
 		case ERequestPrepareEndpointValidationResult:
 			{
-			RDebug::Printf("Asking client to prepare the result of its continuous validation");
+			OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EP0TRANSFERCOMPLETEL_DUP05, "Asking client to prepare the result of its continuous validation");
 			iCaseStep = ERequestValidationResult;
 			iInBufferPtr.Set(iInBuffer->Des());
 			iInBufferPtr.Zero(); //reset
@@ -289,14 +310,14 @@
 			break;
 	
 		case ERequestValidationResult:
-			RDebug::Printf("Collect client's return validation  result in a pass or fail string ...");
-			RDebug::RawPrint(*iInBuffer);
-			RDebug::Printf("\n");
+			OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EP0TRANSFERCOMPLETEL_DUP06, "Collect client's return validation  result in a pass or fail string ...");
+            OstTraceData(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EP0TRANSFERCOMPLETEL_DUP56, "", iInBuffer->Ptr(), iInBuffer->Length());
+			OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EP0TRANSFERCOMPLETEL_DUP07, "\n");
 			iInBufferPtr.Set(iInBuffer->Des());
 			if(iInBufferPtr.Compare(KClientPassString) == 0)
 				{
-				RDebug::Printf("Client Validation Result is a PASS");
-				RDebug::Printf("This is the FINAL check - the whole test has a PASSED");
+				OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EP0TRANSFERCOMPLETEL_DUP08, "Client Validation Result is a PASS");
+				OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EP0TRANSFERCOMPLETEL_DUP09, "This is the FINAL check - the whole test has a PASSED");
 				iCaseStep = EPassed;
 				TTestCasePassed request;
 				iControlEp0->SendRequest(request,this);
@@ -306,7 +327,7 @@
 				TBuf<256> msg;
 				_LIT(lit, "<Error> Bulk data VALIDATION check was NOT successful");
 				msg.Format(lit);
-				RDebug::Print(msg);
+				OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EP0TRANSFERCOMPLETEL_DUP10, msg);
 				iCaseStep = EFailed;
 				TTestCaseFailed request(KErrCorrupt,msg);
 				iControlEp0->SendRequest(request,this);
@@ -314,19 +335,20 @@
 			break;
 	
 		default:
-			RDebug::Printf("<Error> Unknown test step");
+			OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_EP0TRANSFERCOMPLETEL_DUP11, "<Error> Unknown test step");
 			TestFailed(KErrUnknown);
 			break;
 		}
+	OstTraceFunctionExit1( CUT_PBASE_T_USBDI_1229_EP0TRANSFERCOMPLETEL_EXIT_DUP01, this );
 	}
 	
 void CUT_PBASE_T_USBDI_1229::TransferCompleteL(TInt aTransferId,TInt aCompletionCode)
 	{
-	LOG_FUNC
+	OstTraceFunctionEntryExt( CUT_PBASE_T_USBDI_1229_TRANSFERCOMPLETEL_ENTRY, this );
 	Cancel();
 	
 	iTransferResult = KErrNone;
-	RDebug::Printf("Transfer completed (id=%d), aCompletionCode = %d, test step = %d",aTransferId, aCompletionCode, iCaseStep);
+	OstTraceExt3(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_TRANSFERCOMPLETEL, "Transfer completed (id=%d), aCompletionCode = %d, test step = %d",aTransferId, aCompletionCode, iCaseStep);
 
 
 	switch(iCaseStep)
@@ -348,12 +370,12 @@
 				iMsg.Format(lit, iTransferResult, KBulkTransferOutId[0], KBulkTransferOutId[1], aTransferId);
 				break;
 				}
-			RDebug::Printf("Transfer OUT %d completed - num bytes sent = %d", aTransferId, iNumWriteBytesRequested);
+			OstTraceExt2(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_TRANSFERCOMPLETEL_DUP01, "Transfer OUT %d completed - num bytes sent = %d", aTransferId, iNumWriteBytesRequested);
 			
 			if(PerformNextTransfer(aTransferId)==EFalse)
 				{
 				iTransferComplete |= aTransferId;
-				RDebug::Printf("All transfer OUT %ds completed (Transfer Completion Aggregation Mask 0x%x)", aTransferId, iTransferComplete);
+				OstTraceExt2(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_TRANSFERCOMPLETEL_DUP02, "All transfer OUT %ds completed (Transfer Completion Aggregation Mask 0x%x)", aTransferId, iTransferComplete);
 				}
 			
 			if(iTransferResult==KErrNone && (iTransferComplete & KBulkTransferIdMask) == KBulkTransferIdMask)
@@ -361,7 +383,7 @@
 				/*
 				Transfers all complete - now ask device to validate first interface's transfer OUT
 				*/
-				RDebug::Printf("All Transfers Completed Successfully: Transfer Completion Aggregation Mask 0x%x", iTransferComplete);
+				OstTrace1(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_TRANSFERCOMPLETEL_DUP03, "All Transfers Completed Successfully: Transfer Completion Aggregation Mask 0x%x", iTransferComplete);
 				if(iTransferResult==KErrNone)
 					{
 					iBulkTestTimer->Cancel(); //Cancel Timer 
@@ -374,9 +396,9 @@
 						}
 					if(KMaxBytesReadDiffPercentage*iDeviceMaxTimedNumBytesRead > KPercent*iDeviceMinTimedNumBytesRead)
 						{
-						RDebug::Printf("Device APPARENTLY reading rate erratic:-");
-						RDebug::Printf("Min Timed Number of Bytes = %d", iDeviceMinTimedNumBytesRead);
-						RDebug::Printf("Max Timed Number of Bytes = %d", iDeviceMaxTimedNumBytesRead);
+						OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_TRANSFERCOMPLETEL_DUP04, "Device APPARENTLY reading rate erratic:-");
+						OstTrace1(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_TRANSFERCOMPLETEL_DUP05, "Min Timed Number of Bytes = %d", iDeviceMinTimedNumBytesRead);
+						OstTrace1(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_TRANSFERCOMPLETEL_DUP06, "Max Timed Number of Bytes = %d", iDeviceMaxTimedNumBytesRead);
 						iTransferResult = KErrTooBig;
 						iDeviceMaxTimedNumBytesRead = 0;
 						iDeviceMinTimedNumBytesRead = KMaxTUint;
@@ -424,14 +446,15 @@
 			iCaseStep = EDelayedTransferComplete; //so that we move forward when the EP0 transfer has completed
 			}
 		}
+	OstTraceFunctionExit1( CUT_PBASE_T_USBDI_1229_TRANSFERCOMPLETEL_EXIT, this );
 	}
 	
 void CUT_PBASE_T_USBDI_1229::DeviceInsertedL(TUint aDeviceHandle)
 	{
-	LOG_FUNC
+	OstTraceFunctionEntryExt( CUT_PBASE_T_USBDI_1229_DEVICEINSERTEDL_ENTRY, this );
 	
 	Cancel();
-	RDebug::Printf("this - %08x", this);
+	OstTrace1(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_DEVICEINSERTEDL, "this - %08x", this);
 	
 	TBuf<256> msg;
 	TInt err = KErrNone;
@@ -458,7 +481,7 @@
 			iOutTransfer[1] = new (ELeave) CBulkTransfer(iTestPipeInterface1BulkOut,iUsbInterface1,KBulkMaxTransferSize,*this,KBulkTransferOutId[1]);
 			
 			// Initialise the descriptors for transfer		
-			RDebug::Printf("Initialising the transfer descriptors - interface 1");
+			OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_DEVICEINSERTEDL_DUP01, "Initialising the transfer descriptors - interface 1");
 			err = iUsbInterface1.InitialiseTransferDescriptors();
 			if(err != KErrNone)
 				{
@@ -469,7 +492,7 @@
 		}
 	if(err != KErrNone)
 		{
-		RDebug::Print(msg);
+		OstTrace0(TRACE_NORMAL, CUT_PBASE_T_USBDI_1229_DEVICEINSERTEDL_DUP02, msg);
 		iCaseStep = EFailed;
 		TTestCaseFailed request(err,msg);
 		iControlEp0->SendRequest(request,this);
@@ -482,14 +505,17 @@
 		iDeviceNumBytesReadInTotal = 0;
 		RequestNumBytesSent(KBaseTimer);
 		}
+	OstTraceFunctionExit1( CUT_PBASE_T_USBDI_1229_DEVICEINSERTEDL_EXIT, this );
 	}
 
 void CUT_PBASE_T_USBDI_1229::HandleBulkTestTimerFired()
 	{
+	OstTraceFunctionEntry1( CUT_PBASE_T_USBDI_1229_HANDLEBULKTESTTIMERFIRED_ENTRY, this );
 	if(iCaseStep == ETransfer)
 		{
 		RequestNumBytesSent(KTestTimer);
 		}
+	OstTraceFunctionExit1( CUT_PBASE_T_USBDI_1229_HANDLEBULKTESTTIMERFIRED_EXIT, this );
 	}
 	
 	} //end namespace