MCL/sf/os/kernelhwsrv: comparison kernel/eka/drivers/medmmc/medmmc.cpp

equal deleted inserted replaced

-:0bf4040442f9
+:46fffbe7b5a7
 //
 #include "mmc.h"
 #include "pbusmedia.h"
 #include <drivers/emmcptn.h>
+#include "OstTraceDefinitions.h"
+#ifdef OST_TRACE_COMPILER_IN_USE
+#include "locmedia_ost.h"
+#ifdef __VC32__
+#pragma warning(disable: 4127) // disabling warning "conditional expression is constant"
+#endif
+#include "medmmcTraces.h"
+#endif
 #if defined(__DEMAND_PAGING__)
 	// If in debug mode, enable paging stats and their retrieval using DLocalDrive::EControlIO
 	#if defined( _DEBUG)
 		#define __TEST_PAGING_MEDIA_DRIVER__
 // ======== DPhysicalDeviceMediaMmcFlash ========
 DPhysicalDeviceMediaMmcFlash::DPhysicalDeviceMediaMmcFlash()
 	{
+	OstTraceFunctionEntry1( DPHYSICALDEVICEMEDIAMMCFLASH_DPHYSICALDEVICEMEDIAMMCFLASH_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("=mmd:ctr"));
 	iUnitsMask = 0x01;
 	iVersion = TVersion(KMediaDriverInterfaceMajorVersion,KMediaDriverInterfaceMinorVersion,KMediaDriverInterfaceBuildVersion);
+	OstTraceFunctionExit1( DPHYSICALDEVICEMEDIAMMCFLASH_DPHYSICALDEVICEMEDIAMMCFLASH_EXIT, this );
 	}
 TInt DPhysicalDeviceMediaMmcFlash::Install()
 	{
+	OstTraceFunctionEntry1( DPHYSICALDEVICEMEDIAMMCFLASH_INSTALL_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("=mmd:ins"));
 	_LIT(KDrvNm, "Media.MmcF");
-	return SetName(&KDrvNm);
+	TInt r = SetName(&KDrvNm);
+	OstTraceFunctionExitExt( DPHYSICALDEVICEMEDIAMMCFLASH_INSTALL_EXIT, this, r );
+	return r;
 	}
 void DPhysicalDeviceMediaMmcFlash::GetCaps(TDes8& /* aDes */) const
 	{
 TInt DPhysicalDeviceMediaMmcFlash::Info(TInt aFunction, TAny* /*a1*/)
 //
 // Return the priority of this media driver
 //
 	{
+	OstTraceExt2(TRACE_FLOW, DPHYSICALDEVICEMEDIAMMCFLASH_INFO_ENTRY ,"DPhysicalDeviceMediaMmcFlash::Info;aFunction=%d;this=%x", aFunction, (TUint) this);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("=mmd:info"));
 	if (aFunction==EPriority)
+	    {
+		OstTraceFunctionExitExt( DPHYSICALDEVICEMEDIAMMCFLASH_INFO_EXIT1, this, KMediaDriverPriorityNormal );
 		return KMediaDriverPriorityNormal;
+	    }
 	// Don't close media driver when peripheral bus powers down. This avoids the need for Caps() to power up the stack.
 	if (aFunction==EMediaDriverPersistent)
+	    {
+		OstTraceFunctionExitExt( DPHYSICALDEVICEMEDIAMMCFLASH_INFO_EXIT2, this, KErrNone );
 		return KErrNone;
+	    }
+	OstTraceFunctionExitExt( DPHYSICALDEVICEMEDIAMMCFLASH_INFO_EXIT3, this, KErrNotSupported );
 	return KErrNotSupported;
 	}
 TInt DPhysicalDeviceMediaMmcFlash::Validate(TInt aDeviceType, const TDesC8* /*aInfo*/, const TVersion& aVer)
 	{
+	OstTraceExt2(TRACE_FLOW, DPHYSICALDEVICEMEDIAMMCFLASH_VALIDATE_ENTRY ,"DPhysicalDeviceMediaMmcFlash::Validate;aDeviceType=%d;this=%x", aDeviceType, (TUint) this);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("=mmd:validate aDeviceType %d", aDeviceType));
 	if (!Kern::QueryVersionSupported(iVersion,aVer))
+	    {
+		OstTraceFunctionExitExt( DPHYSICALDEVICEMEDIAMMCFLASH_VALIDATE_EXIT1, this, KErrNotSupported );
 		return KErrNotSupported;
+	    }
 	if (aDeviceType!=MEDIA_DEVICE_MMC)
+	    {
+		OstTraceFunctionExitExt( DPHYSICALDEVICEMEDIAMMCFLASH_VALIDATE_EXIT2, this, KErrNotSupported );
 		return KErrNotSupported;
+	    }
+	OstTraceFunctionExitExt( DPHYSICALDEVICEMEDIAMMCFLASH_VALIDATE_EXIT3, this, KErrNone );
 	return KErrNone;
 	}
 TInt DPhysicalDeviceMediaMmcFlash::Create(DBase*& aChannel, TInt aMediaId, const TDesC8* /*aInfo*/, const TVersion& aVer)
 //
 // Create an MMC Card media driver.
 //
 	{
+	OstTraceExt2(TRACE_FLOW, DPHYSICALDEVICEMEDIAMMCFLASH_CREATE_ENTRY, "DPhysicalDeviceMediaMmcFlash::Create;aMediaId=%d;this=%x", aMediaId, (TUint) this);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:crt"));
 	if (!Kern::QueryVersionSupported(iVersion,aVer))
+	    {
+		OstTraceFunctionExitExt( DPHYSICALDEVICEMEDIAMMCFLASH_CREATE_EXIT1, this, KErrNotSupported );
 		return KErrNotSupported;
+	    }
 	DMmcMediaDriverFlash* pD = new DMmcMediaDriverFlash(aMediaId);
 	aChannel=pD;
 	TInt r=KErrNoMemory;
 		r=pD->DoCreate(aMediaId);
 	if (r==KErrNone)
 		pD->OpenMediaDriverComplete(KErrNone);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:mdf"));
+	OstTraceFunctionExitExt( DPHYSICALDEVICEMEDIAMMCFLASH_CREATE_EXIT2, this, r );
 	return r;
 	}
 // ======== DMmcMediaDriverFlash ========
 	iDataTransferCallBackDfc(DMmcMediaDriverFlash::DataTransferCallBackDfc, this, 1)
 	{
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("=mmd:mmd"));
 	// NB aMedia Id = the media ID of the primary media, iMediaId = the media ID of this media
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("DMmcMediaDriverFlash(), iMediaId %d, aMediaId %d\n", iMediaId, aMediaId));
+	OstTraceExt2( TRACE_FLOW, DMMCMEDIADRIVERFLASH_DMMCMEDIADRIVERFLASH, "> DMmcMediaDriverFlash::DMmcMediaDriverFlash;aMediaId=%d;iMediaId=%d", (TInt) aMediaId, (TInt) iMediaId );
 	}
 #pragma warning( default : 4355 )
 TInt DMmcMediaDriverFlash::DoCreate(TInt /*aMediaId*/)
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_DOCREATE_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:opn"));
 	iSocket = ((DMMCSocket*)((DPBusPrimaryMedia*)iPrimaryMedia)->iSocket);
 	if(iSocket == NULL)
-		return(KErrNoMemory);
+	    {
+		OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DOCREATE_EXIT1, this, KErrNoMemory );
+		return KErrNoMemory;
+	    }
 	iCardNumber = ((DPBusPrimaryMedia*)iPrimaryMedia)->iSlotNumber;
 	iStack = iSocket->Stack(KStackNumber);
 	iCard = iStack->CardP(CardNum());
 	Stack().MachineInfo(machineInfo);
 	TInt slotFlag = iCardNumber == 0 ? TMMCMachineInfo::ESlot1Internal : TMMCMachineInfo::ESlot2Internal;
 	iInternalSlot = machineInfo.iFlags & slotFlag;
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("DMmcMediaDriverFlash::DoCreate() slotNumber %d iInternalSlot %d", iCardNumber, iInternalSlot));
+	OstTraceExt2(TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DOCREATE_SLOT, "slotNumber=%d; iInternalSlot=%d", iCardNumber, iInternalSlot);
 	iSessionEndDfc.SetDfcQ(&iSocket->iDfcQ);
 	iDataTransferCallBackDfc.SetDfcQ(&iSocket->iDfcQ);
 	// check right type of card
 	if ((iMediaType=iCard->MediaType())==EMultiMediaNotSupported)
-		return(KErrNotReady);
+	    {
+		OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DOCREATE_EXIT2, this, KErrNotReady );
+		return KErrNotReady;
+	    }
 	// get card characteristics
 	const TCSD& csd = iCard->CSD();
 	iBlkLenLog2 = iCard->MaxReadBlLen();
 	iBlkLen = 1 << iBlkLenLog2;
 	iReadBlPartial = iCard->IsHighCapacity() ? EFalse : csd.ReadBlPartial();
 	// allocate and initialize session object
 	TInt r = AllocateSession();
 	if (r!= KErrNone)
+	    {
+		OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DOCREATE_EXIT3, this, r );
 		return r;
+	    }
 	// get buffer memory from EPBUS
 	TUint8* buf;
 	TInt bufLen;
 	TInt minorBufLen;
 	TInt mediaIndex = iMediaId - primaryMedia->iMediaId;
 	TInt bufIndex = (iCardNumber * numMedia)  + mediaIndex;
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("physicalCardSlots %d, iCardNumber %d\n",  physicalCardSlots, iCardNumber));
+	OstTraceExt2(TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DOCREATE_VARS1, "physicalCardSlots=%d; iCardNumber=%d", physicalCardSlots, iCardNumber);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("iMediaId %d numMedia %d, mediaIndex %d, totalNumMedia %d, bufIndex %d\n",
 			  iMediaId, numMedia, mediaIndex, totalNumMedia, bufIndex));
+	OstTraceExt5(TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DOCREATE_VARS2, "iMediaId=%d; numMedia=%d; mediaIndex=%d; totalNumMedia=%d; bufIndex=%d", iMediaId, numMedia, mediaIndex, totalNumMedia, bufIndex);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("bufLen1 %08X iCacheBuf1 %08X", bufLen, iCacheBuf));
+	OstTraceExt2(TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DOCREATE_CACHEBUF1, "bufLen1=0x%08x; iCacheBuf1=0x%08x", (TUint) bufLen, (TUint) iCacheBuf);
 	bufLen/= totalNumMedia;
 	iCacheBuf+= bufIndex * bufLen;
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("bufLen2 %08X iCacheBuf2 %08X", bufLen, iCacheBuf));
+	OstTraceExt2(TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DOCREATE_CACHEBUF2, "bufLen2=0x%08x; iCacheBuf2=0x%08x", (TUint) bufLen, (TUint) iCacheBuf);
 	iBlocksInBuffer = bufLen >> iBlkLenLog2;	// may lose partial block
 	if(iSocket->SupportsDoubleBuffering())
 		{
 		// Ensure that there's always an even number of buffered blocks when double-buffering
 	iPrWtGpLen = iCard->PreferredWriteGroupLength();
 	// check the preferred write group length is a power of two
 	if(iPrWtGpLen == 0 || (iPrWtGpLen & (~iPrWtGpLen + 1)) != iPrWtGpLen)
-		return(KErrNotReady);
+	    {
+		OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DOCREATE_EXIT4, this, KErrNotReady );
+		return KErrNotReady;
+	    }
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("iMaxBufSize %d iPrWtGpLen %d\n", iMaxBufSize, iPrWtGpLen));
+	OstTraceExt2(TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DOCREATE_IPRWTGPLEN1, "iMaxBufSize=%d; iPrWtGpLen1=%d", iMaxBufSize, iPrWtGpLen);
 	// ensure the preferred write group length is as large as possible
 	// so we can write to more than one write group at once
 	while (iPrWtGpLen < (TUint32) iMaxBufSize)
 		iPrWtGpLen <<= 1;
 	while (iPrWtGpLen > (TUint32) iMaxBufSize)
 		iPrWtGpLen >>= 1;
 	iPrWtGpMsk = TInt64(iPrWtGpLen - 1);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("iPrWtGpLen #2 %d\n", iPrWtGpLen));
+	OstTrace1(TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DOCREATE_IPRWTGPLEN2, "iPrWtGpLen2=%d", iPrWtGpLen);
 	// allocate index for cached blocks
 	iCachedBlocks =	KernAlloc<TInt64>(iBlocksInBuffer);
 	if (iCachedBlocks == 0)
-		return(KErrNoMemory);
+	    {
+		OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DOCREATE_EXIT5, this, KErrNoMemory );
+		return KErrNoMemory;
+	    }
 	InvalidateCache();
 	iLstUsdCchEnt = iBlocksInBuffer - 1;		// use entry 0 first
 	// allocate read lookup index
 	iGamma = KernAlloc<TInt>(iBlocksInBuffer);
 	if (iGamma == 0)
-		return(KErrNoMemory);
+	    {
+		OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DOCREATE_EXIT6, this, KErrNoMemory );
+		return KErrNoMemory;
+	    }
 	// get current requirements
 	iReadCurrentInMilliAmps = csd.MaxReadCurrentInMilliamps();
 	iWriteCurrentInMilliAmps = csd.MaxWriteCurrentInMilliamps();
 	// get preferred erase information for format operations
 	const TInt err = iCard->GetEraseInfo(iEraseInfo);
 	if(err != KErrNone)
-		return(err);
+	    {
+		OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DOCREATE_EXIT7, this, err );
+		return err;
+	    }
 	iEraseUnitMsk = TInt64(iEraseInfo.iPreferredEraseUnitSize) - 1;
 	// Retrieve the demand paging info from the PSL of the stack
 	Stack().DemandPagingInfo(iDemandPagingInfo);
 	//
 	if(iInternalSlot)
 		{
 		iMmcPartitionInfo = CreateEmmcPartitionInfo();
 		if(iMmcPartitionInfo == NULL)
+		    {
+			OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DOCREATE_EXIT8, this, KErrNoMemory );
 			return KErrNoMemory;
+		    }
 		TInt err = iMmcPartitionInfo->Initialise(this);
 		if(err != KErrNone)
+		    {
+			OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DOCREATE_EXIT9, this, err );
 			return err;
+		    }
 		}
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:opn"));
-	return(KErrNone);
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DOCREATE_EXIT10, this, KErrNone );
+	return KErrNone;
 	}
 void DMmcMediaDriverFlash::Close()
 //
 // Close the media driver - also called on media change
 //
 	{
+	OstTraceFunctionEntry0( DMMCMEDIADRIVERFLASH_CLOSE_ENTRY );
 	__KTRACE_OPT(KPBUSDRV,Kern::Printf("=mmd:cls"));
 	EndInCritical();
 	iSessionEndDfc.Cancel();
 	iDataTransferCallBackDfc.Cancel();
 	CompleteRequest(KErrNotReady);
 	DMediaDriver::Close();
+	OstTraceFunctionExit0( DMMCMEDIADRIVERFLASH_CLOSE_EXIT );
 	}
 DMmcMediaDriverFlash::~DMmcMediaDriverFlash()
 	{
+	OstTraceFunctionEntry0( DMMCMEDIADRIVERFLASH_DMMCMEDIADRIVERFLASH_ENTRY );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:dtr"));
 	iSessionEndDfc.Cancel();
 	iDataTransferCallBackDfc.Cancel();
 	Kern::Free(iGamma);
 	delete iMmcPartitionInfo;
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:dtr"));
+	OstTraceFunctionExit0( DMMCMEDIADRIVERFLASH_DMMCMEDIADRIVERFLASH_EXIT );
 	}
 TInt DMmcMediaDriverFlash::AllocateSession()
 	{
+OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_ALLOCATESESSION_ENTRY, this );
 	// already allocated ?
 	if (iSession != NULL)
+	    {
+		OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_ALLOCATESESSION_EXIT1, this, KErrNone );
 		return KErrNone;
+	    }
 	iSession = iStack->AllocSession(iSessionEndCallBack);
 	if (iSession == NULL)
+	    {
+		OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_ALLOCATESESSION_EXIT2, this, KErrNoMemory );
 		return KErrNoMemory;
+	    }
 	iSession->SetStack(iStack);
 	iSession->SetCard(iCard);
 	iSession->SetDataTransferCallback(iDataTransferCallBack);
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_ALLOCATESESSION_EXIT3, this, KErrNone );
 	return KErrNone;
 	}
 // ---- media access ----
 //
 // set up iReqStart, iReqEnd and iReqCur and launch first read.  Subsequent reads
 // will be launched from the callback DFC.
 //
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_DOREAD_ENTRY, this );
 	TInt r = CheckDevice(EMReqTypeNormalRd);
-	if (r != KErrNone) return r;
+	if (r != KErrNone)
+	    {
+	    OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DOREAD_EXIT1, this, r );
+	    return r;
+	    }
 	const TInt64 pos(iCurrentReq->Pos());
 	TUint32 length(I64LOW(iCurrentReq->Length()));
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:dr:0x%lx,0x%x", pos, length));
+	OstTraceExt2( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DO_READ, "Position=0x%lx; Length=0x%x", (TUint) pos, (TUint) length);
 	__ASSERT_DEBUG(CurrentRequest() == EMReqIdle, Panic(EDRInUse));
 	__ASSERT_DEBUG(pos < TotalSizeInBytes(), Panic(EDRStart));
 	__ASSERT_DEBUG(iCurrentReq->Length() >= 0, Panic(EDRNotPositive));
 	__ASSERT_DEBUG(TotalSizeInBytes() >= pos + length, Panic(EDREnd));
 			else if ( (iReqEnd - iPhysStart) > iMaxBufSize && iSocket->SupportsDoubleBuffering() && !iReadToEndOfCard)
 				r = LaunchDBRead();
 			else
 				r = LaunchRead(iReqCur, length);
-			if (r == KErrNone) return r;
+			if (r == KErrNone)
+			    {
+			    OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DOREAD_EXIT2, this, r );
+			    return r;
+			    }
 			}
 		}
 	else
 		{
 #if defined(__DEMAND_PAGING__) && !defined(__WINS__)
 	if(r == KErrNone)
 		r = KErrCompletion;
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:dr:%d", r));
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DOREAD_EXIT3, this, r );
 	return r;
 	}
 TInt DMmcMediaDriverFlash::LaunchRead(TInt64 aStart, TUint32 aLength)
 // iReq* instance variables.  It sets iPhysStart and iPhysEnd to the region that was actually
 // read into iIntBuf. iIntBuf can be set to a cached entry or to the minor buffer.  It is
 // assumed that before this function is called that ReadDataUntilCacheExhausted() has been used.
 //
 	{
+	OstTraceFunctionEntryExt( DMMCMEDIADRIVERFLASH_LAUNCHREAD_ENTRY, this );
+	OstTraceExt2( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_LAUNCHREAD, "position=0x%lx; length=0x%x", (TUint) iCurrentReq->Pos(), (TUint) I64LOW(iCurrentReq->Length()));
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:lr:0x%lx,0x%x", aStart, aLength));
 	__ASSERT_DEBUG(TotalSizeInBytes() > aStart, Panic(ELRStart));
 	__ASSERT_DEBUG(aLength > 0, Panic(ELRNotPositive));
 	__ASSERT_DEBUG(TotalSizeInBytes() >= aStart + aLength, Panic(ELREnd));
 	__ASSERT_CACHE(GetCachedBlock(aStart & ~iBlkMsk) == 0, Panic(ELRCached));
 		}
 	TInt r = EngageAndSetReadRequest(EMReqRead);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:lr:%d", r));
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_LAUNCHREAD_EXIT, this, r );
 	return r;
 	}
 TInt DMmcMediaDriverFlash::LaunchDBRead()
 //
 // iReq* instance variables.  It sets iPhysStart and iPhysEnd to the region that was actually
 // read into iIntBuf. iIntBuf can be set to a cached entry or to the minor buffer.  It is
 // assumed that before this function is called that ReadDataUntilCacheExhausted() has been used.
 //
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_LAUNCHDBREAD_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:ldbr:0x%lx,0x%x", iReqCur, I64LOW(iReqEnd - iReqCur)));
+	OstTraceExt2( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_LAUNCHDBREAD, "position=0x%lx; length=0x%x", (TInt) iReqCur, (TInt) I64LOW(iReqEnd - iReqCur));
 	__ASSERT_DEBUG(TotalSizeInBytes() > iReqCur, Panic(ELRStart));
 	__ASSERT_DEBUG(I64LOW(iReqEnd - iReqCur) > 0, Panic(ELRNotPositive));
 	__ASSERT_DEBUG(TotalSizeInBytes() >= iReqEnd, Panic(ELREnd));
 	__ASSERT_CACHE(GetCachedBlock(iReqCur & ~iBlkMsk) == 0, Panic(ELRCached));
 	__ASSERT_DEBUG(iSession != NULL, Panic(ECFSessPtrNull));
 	TInt r = EngageAndSetReadRequest(EMReqRead);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:ldbr:%d", r));
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_LAUNCHDBREAD_EXIT, this, r );
 	return r;
 	}
 TInt DMmcMediaDriverFlash::LaunchPhysRead(TInt64 aStart, TUint32 aLength)
 // This function does not maintain the iReq* instance variables.
 // It is assumed that before this function is called that
 // ReadDataUntilCacheExhausted() has been used.
 //
 	{
+	OstTraceFunctionEntryExt( DMMCMEDIADRIVERFLASH_LAUNCHPHYSREAD_ENTRY, this );
+	OstTraceExt2( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_LAUNCHPHYSREAD, "position=0x%lx; length=0x%x", (TInt) iReqCur, (TInt) I64LOW(iReqEnd - iReqCur));
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:physr:0x%lx,0x%x", aStart, aLength));
 	__ASSERT_DEBUG(TotalSizeInBytes() > aStart, Panic(ELRStart));
 	__ASSERT_DEBUG(aLength > 0, Panic(ELRNotPositive));
 	__ASSERT_DEBUG(TotalSizeInBytes() >= aStart + aLength, Panic(ELREnd));
 	__ASSERT_CACHE(GetCachedBlock(aStart & ~iBlkMsk) == 0, Panic(ELRCached));
 	TUint32 physLen(I64LOW(iPhysEnd - iPhysStart));
 	if (firstPartial)
 		{
 		__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:physr:FirstPartial"));
+		OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_LAUNCH_PHYSREAD_FP, "FirstPartial");
 		// first index does not start on block boundary
 		// iIntBuf linear address is used for IPC within DoReadDataTransferCallBack()
 		iRdROB |= KIPCWrite;
 		iIntBuf = ReserveReadBlocks(iPhysStart, iPhysStart+iBlkLen,(TUint32*)&physLength);
 		r = EngageAndSetReadRequest(EMReqRead);
 		}
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:lphysr:%d", r));
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_LAUNCHPHYSREAD_EXIT, this, r );
 	return r;
 	}
 TInt DMmcMediaDriverFlash::DoWrite()
 // set up iReqStart, iReqEnd, and iReqCur, and launch first write.  Any subsequent
 // writes are launched from the session end DFC.  LaunchWrite() handles pre-reading
 // any sectors that are only partially modified.
 //
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_DOWRITE_ENTRY, this );
 	const TInt64 pos = iCurrentReq->Pos();
 	const TUint32 length = I64LOW(iCurrentReq->Length());
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:dw:0x%lx,0x%x", pos, length));
+	OstTraceExt2( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DOWRITE, "position=0x%lx; length=0x%x", (TUint) pos, (TUint) length);
 	__ASSERT_DEBUG(CurrentRequest() == EMReqIdle, Panic(EDWInUse));
 	__ASSERT_DEBUG(pos < TotalSizeInBytes(), Panic(EDWStart));
 	__ASSERT_DEBUG(length > 0, Panic(EDWNotPositive));
 	__ASSERT_DEBUG(TotalSizeInBytes() >= pos + length, Panic(EDWEnd));
 	const TInt r = LaunchWrite(iReqStart, length, EMReqWrite);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:dw:%d", r));
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DOWRITE_EXIT, this, r );
 	return r;
 	}
 TInt DMmcMediaDriverFlash::DoFormat()
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_DOFORMAT_ENTRY, this );
 	const TInt64 pos = iCurrentReq->Pos();
 	const TUint32 length = I64LOW(iCurrentReq->Length());
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:df:0x%lx,0x%x", pos, length));
+	OstTraceExt2( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DOFORMAT, "position=0x%lx; length=0x%x", (TUint) pos, (TUint) length);
 	__ASSERT_DEBUG(CurrentRequest() == EMReqIdle, Panic(EDFInUse));
 	__ASSERT_DEBUG(pos < TotalSizeInBytes(), Panic(EDFStart));
 	__ASSERT_DEBUG(length > 0, Panic(EDFNotPositive));
 	__ASSERT_DEBUG(TotalSizeInBytes() >= pos + length, Panic(EDFEnd));
 	const TInt r = LaunchFormat(iReqStart, I64LOW(iReqEnd - iReqStart));
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:df:%d", r));
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DOFORMAT_EXIT, this, r );
 	return r;
 	}
 TInt DMmcMediaDriverFlash::LaunchFormat(TInt64 aStart, TUint32 aLength)
 //
 // starts writes from DoWrite(), DoFormat() and the session end DFC.  This function does not
 // maintain the iReq* instance variables.  It sets iIntBuf, iPhysStart and iPhysEnd.
 //
 	{
+	OstTraceFunctionEntryExt( DMMCMEDIADRIVERFLASH_LAUNCHFORMAT_ENTRY, this );
+	OstTraceExt2( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_LAUNCHFORMAT, "position=0x%lx; length=0x%x", (TInt) iReqCur, (TInt) I64LOW(iReqEnd - iReqCur));
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:lf:0x%lx,0x%x", aStart, aLength));
 	__ASSERT_DEBUG(TotalSizeInBytes() > aStart, Panic(ELFStart));
 	__ASSERT_DEBUG((aStart & iBlkMsk) == 0, Panic(ELWFmtStAlign));
 	__ASSERT_DEBUG(aLength > 0, Panic(ELFNotPositive));
 	__ASSERT_DEBUG(TotalSizeInBytes() >= aStart + aLength, Panic(ELFEnd));
 			iSession->SetupCIMWriteBlock(I64LOW(iPhysStart >> KMMCardHighCapBlockSizeLog2), iCacheBuf, writeLen >> KMMCardHighCapBlockSizeLog2);
 			}
 		r = EngageAndSetWriteRequest(EMReqFormat);
 		}
+		OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_LAUNCHFORMAT_EXIT, this, r );
 		return r;
 	}
 //
 // starts writes from DoWrite(), DoFormat() and the session end DFC.  This function does not
 // maintain the iReq* instance variables.  It sets iIntBuf, iPhysStart and iPhysEnd.
 //
 	{
+	OstTraceExt4(TRACE_FLOW, DMMCMEDIADRIVERFLASH_LAUNCHWRITE_ENTRY, "DMmcMediaDriverFlash::LaunchWrite;aStart=%Ld;aLength=%x;aMedReq=%d;this=%x", aStart, (TUint) aLength, (TInt) aMedReq, (TUint) this);
+	OstTraceExt2( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_LAUNCHWRITE, "position=0x%lx; length=0x%x", (TInt) iReqCur, (TInt) I64LOW(iReqEnd - iReqCur));
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("\n>mmd:lw:0x%lx,%d,%d", aStart, aLength, aMedReq));
 	__ASSERT_DEBUG(aMedReq == EMReqWrite || aMedReq == EMReqFormat, Panic(ELWRequest));
 	__ASSERT_DEBUG(TotalSizeInBytes() > aStart, Panic(ELWStart));
 	__ASSERT_DEBUG(!(aMedReq == EMReqFormat) || (aStart & iBlkMsk) == 0, Panic(ELWFmtStAlign));
 	__ASSERT_DEBUG(aLength > 0, Panic(ELWNotPositive));
 			} //if (iWtRBM == 0)
 		if (iWtRBM & KWtRBMFst)
 			{
 			__KTRACE_OPT(KPBUSDRV, Kern::Printf("mmd:lw: read-before-modify required on first block"));
+			OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_LAUNCHWRITE_RBMF, "Read-before-modify required on first block");
 			if (iDoPhysicalAddress)
 				iSession->SetupCIMReadBlock(I64LOW(iPhysStart >> KMMCardHighCapBlockSizeLog2), iMinorBuf, iBlkLen >> KMMCardHighCapBlockSizeLog2);
 			else
 				iSession->SetupCIMReadBlock(I64LOW(iPhysStart >> KMMCardHighCapBlockSizeLog2), iIntBuf, iBlkLen >> KMMCardHighCapBlockSizeLog2);
-			return EngageAndSetReadRequest(aMedReq);
+			r = EngageAndSetReadRequest(aMedReq);
+			OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_LAUNCHWRITE_EXIT1, this, r );
+			return r;
 			}
 		else if (iWtRBM & KWtRBMLst)
 			{
 			__KTRACE_OPT(KPBUSDRV, Kern::Printf("mmd:lw: read-before-modify required on last block"));
+			OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_LAUNCHWRITE_RBML, "Read-before-modify required on last block");
 			if(iDoDoubleBuffer || iDoPhysicalAddress)
 				{
 				//
 				// When double-buffering, the result of the RMW-read operation shall be stored
 				// in the minor buffer, otherwise the data would be overwritten before the last
 				const TInt64 lastBlock = iPhysEnd - iBlkLen;		// start posn in media to read from
 				iSession->SetupCIMReadBlock(I64LOW(lastBlock >> KMMCardHighCapBlockSizeLog2), iIntBuf + (lastBlock - iPhysStart), iBlkLen >> KMMCardHighCapBlockSizeLog2);
 				}
 			// Kick off the RMW-read operation for the last block...
-			return EngageAndSetReadRequest(aMedReq);
+			r = EngageAndSetReadRequest(aMedReq);
+			OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_LAUNCHWRITE_EXIT2, this, r );
+			return r;
 			}
 		if (iWtRBM & KWtMinFst)
 			{
 			__KTRACE_OPT(KPBUSDRV, Kern::Printf("mmd:lw:Phys write-first-block-only"));
+			OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_LAUNCHWRITE_FBO, "Write first block only");
 			//Overwrite first block with the new data
 			TInt32 tlen = I64LOW(aStart & iBlkMsk);
 			TInt32 wlen = UMin(I64LOW((iBlkMsk+1) - tlen), aLength);
 			const TInt64 usrOfst = (aStart - iReqStart);
 			TPtr8 tgt(&iMinorBuf[tlen], I64LOW(wlen));
 			if ( (r = iCurrentReq->ReadRemote(&tgt,I64LOW(usrOfst))) != KErrNone)
+			    {
+				OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_LAUNCHWRITE_EXIT3, this, r );
 				return r;
+			    }
 			}
 		if (iWtRBM & KWtMinLst)
 			{
 			__KTRACE_OPT(KPBUSDRV, Kern::Printf("mmd:lw:Phys write-last-block-only"));
+			OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_LAUNCHWRITE_LBO, "Write last block only");
 			iWtRBM &= ~KWtMinLst;
 			//Overwrite last block with the new data
 			const TInt64 medEnds = aStart + aLength;
 			TInt64 tlen = medEnds & iBlkMsk;
 			const TInt64 usrOfst = (aStart - iReqStart);
 			TPtr8 tgt(iCacheBuf, I64LOW(tlen));
 			if ( (r = iCurrentReq->ReadRemote(&tgt,I64LOW(usrOfst+aLength-tlen))) !=KErrNone)
+			    {
+				OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_LAUNCHWRITE_EXIT4, this, r );
 				return r;
+			    }
 			}
 		// no reads required - read data from user buffer and launch write
 		const TInt64 usrOfst = (aStart - iReqStart);
 		const TInt64 bufOfst = aStart - iPhysStart;		// offset into first sector, not whole buffer
 				{
 				iDbEnd = iPhysEnd;
 		iPhysEnd = iPhysStart+physLength;
 		if ((TUint32)physLength > physLen) physLength = physLen; // more memory in fragment than required!
+		OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_LAUNCHWRITE_PHYSICAL, "Physical write request" );
 				iSession->SetupCIMWriteBlock(I64LOW(iPhysStart >> KMMCardHighCapBlockSizeLog2), (TUint8*) physAddr, physLen >> KMMCardHighCapBlockSizeLog2);
 				iSession->Command().iFlags|= KMMCCmdFlagPhysAddr;
 				iSession->EnableDoubleBuffering(physLength >> KDiskSectorShift);
 				}
 			else
 				{
 				__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:lw:Phys:%d", r));
+				OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_LAUNCHWRITE_EXIT5, this, r );
 				return r;
 				}
 			} // if (iDoPhysicalAddress)
 		else
 			{
 			if (r == KErrNone)
 				{
 				if(!iDoDoubleBuffer)
 					{
 					// EPBUSM automatically uses CMD24 instead of CMD25 for single block writes
+					OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_LAUNCHWRITE_STANDARD, "Standard write request" );
 					iSession->SetupCIMWriteBlock(I64LOW(iPhysStart >> KMMCardHighCapBlockSizeLog2), iIntBuf, I64LOW((iPhysEnd - iPhysStart) >> KMMCardHighCapBlockSizeLog2));
 					}
 				else
 					{
 					//
 					// request range. and flag the session to enable double-buffering (as well
 					// as specifying the length of each double-buffered transfer as calculated
 					// in 'len' above).  This is performed only once - the double-buffering
 					// is subsequently handled within the DoDataTransferCallback function.
 					//
+					OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_LAUNCHWRITE_DB, "Double-buffered write request" );
 					iSession->SetupCIMWriteBlock(I64LOW(iPhysStart >> KMMCardHighCapBlockSizeLog2), iIntBuf, I64LOW((((iDbEnd + iBlkMsk) & ~iBlkMsk) - iPhysStart) >> KMMCardHighCapBlockSizeLog2));
 					iSession->EnableDoubleBuffering(I64LOW((len + iBlkMsk) & ~iBlkMsk) >> KDiskSectorShift);
 					// ...and switch to the 'second' buffer, which will be populated in the
 					// data transfer callback in parallel with hardware transfer of the first.
 			r = EngageAndSetWriteRequest(aMedReq);
 		}	// if ((r = CheckDevice(EMReqTypeNormalWr)) == KErrNone)
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:lw:%d", r));
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_LAUNCHWRITE_EXIT6, this, r );
 	return r;
 	}
 TInt DMmcMediaDriverFlash::PartitionInfo(TPartitionInfo& anInfo)
 //
 // Read the partition information for the media.  If the user supplied a password,
 // then unlock the card before trying to read the first sector.
 //
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_PARTITIONINFO_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:rpi"));
 	__ASSERT_DEBUG(CurrentRequest() == EMReqIdle, Panic(ERPIInUse));
 	iPartitionInfo = &anInfo;
 		iHiddenSectors = 0; // Not used for internal media
 		if (KErrNone == r)
 			iMedReq = EMReqEMMCPtnInfo;
-		return(r);
+		OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_PARTITIONINFO_EXIT1, this, r );
+		return r;
 		}
 	// Assume MBR will be present or is not required
 	iMbrMissing = EFalse;
 		{
 		// If the media is locked, we present a default partition entry to the local
 		// media subsystem, which will be updated when the media is finally unlocked.
 		r = CreateDefaultPartition();
 		if (r != KErrNone)
+		    {
+			OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_PARTITIONINFO_EXIT2, this, r );
 			return r;
+		    }
+		OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_PARTITIONINFO_EXIT3, this, KErrLocked );
 		return KErrLocked;
 		}
 	// KErrNone indicates asynchronous completion
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_PARTITIONINFO_EXIT4, this, r );
 	return r;
 	}
 TInt DMmcMediaDriverFlash::LaunchRPIUnlock(TLocalDrivePasswordData& aPasswordData)
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_LAUNCHRPIUNLOCK_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:lru:%d,%d", iCard->IsReady(), iCard->IsLocked()));
+	OstTraceExt2( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_LAUNCHRPIUNLOCK_ICARD, "iCard->IsReady=%d; iCard->IsLocked=%d", iCard->IsReady(), iCard->IsLocked());
 	__ASSERT_DEBUG(iSession != NULL, Panic(ECFSessPtrNull));
 	TInt r = KErrNone;
 	// CMD42 is an adtc, so check state in same way as for write
 			r = EngageAndSetWriteRequest(EMReqUpdatePtnInfo);
 			}
 		}
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:lru:%d", r));
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_LAUNCHRPIUNLOCK_EXIT, this, r );
 	return r;
 	}
 TInt DMmcMediaDriverFlash::LaunchRPIRead()
 //
 // launch read request on first KDiskSectorSize (512) bytes
 //
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_LAUNCHRPIREAD_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf((">mmd:lrr")));
 	__ASSERT_DEBUG(iSession != NULL, Panic(ECFSessPtrNull));
 	// the partition information is read before any other area is read from /
 	// written to, and so does not need to maintain cache coherence.  Therefore
 		iSession->SetupCIMReadBlock(0, iIntBuf);	// aBlocks = 1
 		r = EngageAndSetReadRequest(EMReqPtnInfo);
 		}
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:lrr:%d", r));
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_LAUNCHRPIREAD_EXIT, this, r );
 	return r;
 	}
 TInt DMmcMediaDriverFlash::LaunchRPIErase()
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_LAUNCHRPIERASE_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:lre:%d,%d", iCard->IsReady(), iCard->IsLocked()));
 	__ASSERT_DEBUG(iSession != NULL, Panic(ECFSessPtrNull));
 	TInt r = KErrNone;
 			r = KErrAccessDenied;
 			}
 		else
 			{
 			__KTRACE_OPT(KPBUSDRV, Kern::Printf("mmd:df:EMReqForceErase"));
+			OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_LAUNCHRPIERASE_FORCE_ERASE, "Force erase");
 			iMinorBuf[0] = KMMCLockUnlockErase;
 			iSession->SetupCIMLockUnlock(1, iMinorBuf);
 			r = EngageAndSetWriteRequest(EMReqForceErase);
 			}
 		}
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:lru:%d", r));
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_LAUNCHRPIERASE_EXIT, this, r );
 	return r;
 	}
 TInt DMmcMediaDriverFlash::DecodePartitionInfo()
 //
 // decode partition info that was read into internal buffer
 //
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_DECODEPARTITIONINFO_ENTRY, this );
 	TInt partitionCount=iPartitionInfo->iPartitionCount=0;
 	TInt defaultPartitionNumber=-1;
 	TMBRPartitionEntry* pe;
 	const TUint KMBRFirstPartitionOffsetAligned = KMBRFirstPartitionOffset & ~3;
 	TInt i;
 		// FAT partition ?
 		else if (pe->IsValidDosPartition() || pe->IsValidFAT32Partition() || pe->IsValidExFATPartition())
 			{
 			SetPartitionEntry(&iPartitionInfo->iEntry[partitionCount],pe->iFirstSector,pe->iNumSectors);
 			__KTRACE_OPT(KLOCDPAGING, Kern::Printf("Mmc: FAT partition found at sector #%u", pe->iFirstSector));
+			OstTrace1(TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DECODEPARTITIONINFO_FS,"FAT partition found at sector #%u", pe->iFirstSector);
 			partitionCount++;
 			}
 		else
 			{
 			validPartition = EFalse;
 		// Check that the card address space boundary is not exceeded by the last partition
 		// In case of only 1 partition in the media check also it
 		if(part.iPartitionBaseAddr + part.iPartitionLen > deviceSize)
 			{
 			__KTRACE_OPT(KPBUSDRV, Kern::Printf("Mmc: MBR partition exceeds card memory space"));
+			OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DECODEPARTITIONINFO_PARTCOUNT1, "MBR partition exceeds card memory space" );
 			// Adjust the partition length to card address boundary
 			part.iPartitionLen = (deviceSize - part.iPartitionBaseAddr);
 			// Check that the base address contained valid information
 			if(part.iPartitionLen <= 0)
 				{
 				__KTRACE_OPT(KPBUSDRV, Kern::Printf("Mmc: Invalid base address"));
+				OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DECODEPARTITIONINFO_PARTCOUNT2, "Invalid base address" );
 				// Invalid MBR - assume the boot sector is in the first sector
 				defaultPartitionNumber =-1;
 				partitionCount=0;
 				}
 			}
 				TPartitionEntry& prev = iPartitionInfo->iEntry[i-1];
 				// Check if partitions overlap
 				if(curr.iPartitionBaseAddr < (prev.iPartitionBaseAddr + prev.iPartitionLen))
 					{
 					__KTRACE_OPT(KPBUSDRV, Kern::Printf("Mmc: Overlapping partitions"));
+					OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DECODEPARTITIONINFO_PARTCOUNT3, "Overlapping partitions" );
 					// Adjust the partition length to not overlap the next partition
 					prev.iPartitionLen = (curr.iPartitionBaseAddr - prev.iPartitionBaseAddr);
 					// Check that the base address contained valid information
 					if(prev.iPartitionLen <= 0)
 						{
 						__KTRACE_OPT(KPBUSDRV, Kern::Printf("Mmc: Invalid base address"));
+						OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DECODEPARTITIONINFO_PARTCOUNT4, "Invalid base address" );
 						// Invalid MBR - assume the boot sector is in the first sector
 						defaultPartitionNumber=(-1);
 						partitionCount=0;
 						}
 					}
 mbr_done:
 	if (defaultPartitionNumber==(-1) && partitionCount==0)
 		{
 		__KTRACE_OPT(KPBUSDRV, Kern::Printf("Mmc:PartitionInfo no MBR"));
+		OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DECODEPARTITIONINFO_MBRDONE1, "No MBR" );
 		if (MBRMandatory(iCard))
 			{
 			// If the MBR is missing AND is required, we present a default partition entry to the local
 			// media subsystem, which will be updated when the media is finally formatted
 			__KTRACE_OPT(KPBUSDRV, Kern::Printf("MBR mandatory, defining space for MBR + default partition"));
+			OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DECODEPARTITIONINFO_MBRDONE2, "MBR mandatory, defining space for MBR + default partition" );
 			iMbrMissing = ETrue;
 			TInt r = CreateDefaultPartition();
 			if (r != KErrNone)
+			    {
+				OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DECODEPARTITIONINFO_EXIT1, this, r );
 				return r;
+			    }
 			}
 		else
 			{
 			// Assume it has no MBR, and the Boot Sector is in the 1st sector
 			SetPartitionEntry(&iPartitionInfo->iEntry[0],0,I64LOW(iCard->DeviceSize64()>>KDiskSectorShift));
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<Mmc:PartitionInfo (C:%d)",iPartitionInfo->iPartitionCount));
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("     Partition1 (B:%xH L:%xH)",I64LOW(iPartitionInfo->iEntry[0].iPartitionBaseAddr),I64LOW(iPartitionInfo->iEntry[0].iPartitionLen)));
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("     Partition2 (B:%xH L:%xH)",I64LOW(iPartitionInfo->iEntry[1].iPartitionBaseAddr),I64LOW(iPartitionInfo->iEntry[1].iPartitionLen)));
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("     Partition3 (B:%xH L:%xH)",I64LOW(iPartitionInfo->iEntry[2].iPartitionBaseAddr),I64LOW(iPartitionInfo->iEntry[2].iPartitionLen)));
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("     Partition4 (B:%xH L:%xH)",I64LOW(iPartitionInfo->iEntry[3].iPartitionBaseAddr),I64LOW(iPartitionInfo->iEntry[3].iPartitionLen)));
+	OstTraceDefExt4(OST_TRACE_CATEGORY_RND, TRACE_MMCDEBUG, DMMCMEDIADRIVERFLASH_DECODEPARTITIONINFO_PARTINFO1, "Partition1 (B:0x%x L:0x%x); Partition2 (B:0x%x L:0x%x)", I64LOW(iPartitionInfo->iEntry[0].iPartitionBaseAddr),I64LOW(iPartitionInfo->iEntry[0].iPartitionLen),I64LOW(iPartitionInfo->iEntry[1].iPartitionBaseAddr),I64LOW(iPartitionInfo->iEntry[1].iPartitionLen));
+	OstTraceDefExt4(OST_TRACE_CATEGORY_RND, TRACE_MMCDEBUG, DMMCMEDIADRIVERFLASH_DECODEPARTITIONINFO_PARTINFO2, "Partition3 (B:0x%x L:0x%x); Partition4 (B:0x%x L:0x%x)", I64LOW(iPartitionInfo->iEntry[2].iPartitionBaseAddr),I64LOW(iPartitionInfo->iEntry[2].iPartitionLen),I64LOW(iPartitionInfo->iEntry[3].iPartitionBaseAddr),I64LOW(iPartitionInfo->iEntry[3].iPartitionLen));
 #ifdef _DEBUG
 	TMBRPartitionEntry cPe;
 	if(GetDefaultPartitionInfo(cPe) == KErrNone)
 		{
 		__KTRACE_OPT(KPBUSDRV, Kern::Printf("--       iNumSectors [%08x:%08x] %c       -", pe->iNumSectors,       cPe.iNumSectors,       pe->iNumSectors       == cPe.iNumSectors       ? ' ' : 'X'));
 		__KTRACE_OPT(KPBUSDRV, Kern::Printf("-------------------------------------------"));
 		}
 #endif
-	return(KErrNone);
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DECODEPARTITIONINFO_EXIT2, this, KErrNone );
+	return KErrNone;
 	}
 TInt DMmcMediaDriverFlash::WritePartitionInfo()
 /**
 	Write the default partition table to freshly formatted media
 	@return Standard Symbian OS Error Code
 */
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_WRITEPARTITIONINFO_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:wpi"));
 	__ASSERT_DEBUG(iSession != NULL, Panic(ECFSessPtrNull));
 	TMBRPartitionEntry partitionEntry;
 	TInt err = GetDefaultPartitionInfo(partitionEntry);
 		__KTRACE_OPT(KPBUSDRV, Kern::Printf("    End Head         : %02xh", partitionEntry.iEndHead));
 		__KTRACE_OPT(KPBUSDRV, Kern::Printf("    End Sector       : %02xh", partitionEntry.iEndSector));
 		__KTRACE_OPT(KPBUSDRV, Kern::Printf("    End Cyclinder    : %02xh", partitionEntry.iEndCylinder));
 		__KTRACE_OPT(KPBUSDRV, Kern::Printf("    Relative Sector  : %08xh", partitionEntry.iFirstSector));
 		__KTRACE_OPT(KPBUSDRV, Kern::Printf("    Number of Sectors: %08xh", partitionEntry.iNumSectors));
+		OstTraceExt5(TRACE_MMCDEBUG, DMMCMEDIADRIVERFLASH_WRITEPARTITIONINFO_PARTINFO1, "Boot ID=0x%02x; Start Head=0x%02x; Start Sector=0x%02x; Start Cyclinder=0x%02x; System ID=0x%02x", (TUint) partitionEntry.iX86BootIndicator, (TUint) partitionEntry.iStartHead, (TUint) partitionEntry.iStartSector, (TUint) partitionEntry.iStartCylinder, (TUint) partitionEntry.iPartitionType);
+		OstTraceExt5(TRACE_MMCDEBUG, DMMCMEDIADRIVERFLASH_WRITEPARTITIONINFO_PARTINFO2, "End Head=0x%02x; End Sector=0x%02x; End Cyclinder=0x%02x; Relative Sector=0x%08x; Number of Sectors=0x%08x", (TUint) partitionEntry.iEndHead, (TUint) partitionEntry.iEndSector, (TUint) partitionEntry.iEndCylinder, (TUint) partitionEntry.iFirstSector, (TUint) partitionEntry.iNumSectors);
 		//
 		// Clear all other partition entries and align the partition info into the minor buffer for writing...
 		//
 		memclr(iMinorBuf, KDiskSectorSize);
 		memcpy(&iMinorBuf[KMBRFirstPartitionEntry], &partitionEntry, sizeof(TMBRPartitionEntry));
 		err = EngageAndSetWriteRequest(EMReqUpdatePtnInfo);
 		}
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:wpi:%d", err));
-	return(err);
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_WRITEPARTITIONINFO_EXIT, this, err );
+	return err;
 	}
 TInt DMmcMediaDriverFlash::CreateDefaultPartition()
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_CREATEDEFAULTPARTITION_ENTRY, this );
 	TMBRPartitionEntry defPartition;
 	TInt r = GetDefaultPartitionInfo(defPartition);
 	if (r == KErrNone)
 		{
 		SetPartitionEntry(&iPartitionInfo->iEntry[0], defPartition.iFirstSector, defPartition.iNumSectors);
 		iHiddenSectors = defPartition.iFirstSector;
 		iPartitionInfo->iPartitionCount   = 1;
 		iPartitionInfo->iMediaSizeInBytes = TotalSizeInBytes();
 		}
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_CREATEDEFAULTPARTITION_EXIT, this, r );
 	return r;
 	}
 TInt DMmcMediaDriverFlash::GetDefaultPartitionInfo(TMBRPartitionEntry& aPartitionEntry)
 /**
 	@return Standard Symbian OS Error Code
 */
 	{
 	memclr(&aPartitionEntry, sizeof(TMBRPartitionEntry));
 	TUint16 reservedSectors; // Not used
-	return GetMediaDefaultPartitionInfo(aPartitionEntry, reservedSectors, iCard);
+	TInt r = GetMediaDefaultPartitionInfo(aPartitionEntry, reservedSectors, iCard);
+	return r;
 	}
 void DMmcMediaDriverFlash::SetPartitionEntry(TPartitionEntry* aEntry, TUint aFirstSector, TUint aNumSectors)
 //
 // auxiliary static function to record partition information in TPartitionEntry object
 //
 	{
+	OstTraceFunctionEntry0( DMMCMEDIADRIVERFLASH_SETPARTITIONENTRY_ENTRY );
 	aEntry->iPartitionBaseAddr=aFirstSector;
 	aEntry->iPartitionBaseAddr<<=KDiskSectorShift;
 	aEntry->iPartitionLen=aNumSectors;
 	aEntry->iPartitionLen<<=KDiskSectorShift;
 	aEntry->iPartitionType=KPartitionTypeFAT12;
+	OstTraceFunctionExit0( DMMCMEDIADRIVERFLASH_SETPARTITIONENTRY_EXIT );
 	}
 TInt DMmcMediaDriverFlash::DoPasswordOp()
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_DOPASSWORDOP_ENTRY, this );
 	// Reconstruct password data structure in our address space
 	TLocalDrivePasswordData clientData;
 	TInt r = iCurrentReq->ReadRemoteRaw(&clientData, sizeof(TLocalDrivePasswordData));
 	TMediaPassword oldPassword;
 	// This will complete the request in the event of an error
 	if(r != KErrNone)
 		PartitionInfoComplete(r);
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_DOPASSWORDOP_EXIT, this, KErrNone );
 	return KErrNone; // ensures to indicate asynchronoous completion
 	}
 void DMmcMediaDriverFlash::PasswordControl(TInt aFunc, TLocalDrivePasswordData& aData)
 //
 // must be unlocked for this function.  A locked card is unlocked when it is mounted,
 // to read the partition information.  This is done from ReadPartitionInfo() and
 // LaunchRPIUnlock().
 //
 	{
+	OstTraceExt2(TRACE_FLOW, DMMCMEDIADRIVERFLASH_PASSWORDCONTROL_ENTRY ,"DMmcMediaDriverFlash::PasswordControl;aFunc=%d;this=%x", aFunc, (TUint) this);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:pc:%d", (TInt) aFunc));
 	__ASSERT_DEBUG(CurrentRequest() == EMReqIdle, Panic(EPCInUse));
 	__ASSERT_DEBUG(aFunc == DLocalDrive::EPasswordLock || aFunc == DLocalDrive::EPasswordClear, Panic(EPCFunc));
 	__ASSERT_DEBUG(iSession != NULL, Panic(ECFSessPtrNull));
 	// complete immediately if error occured
 	if (r != KErrNone)
 		CompleteRequest(r);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:pc:%d", r));
+	OstTraceFunctionExit1( DMMCMEDIADRIVERFLASH_PASSWORDCONTROL_EXIT, this );
 	}
 // ---- device status, callback DFC ----
 TInt DMmcMediaDriverFlash::CheckDevice(TMediaReqType aReqType)
 //
 // Check the device before initiating a command
 //
 	{
+	OstTraceExt2(TRACE_FLOW, DMMCMEDIADRIVERFLASH_CHECKDEVICE_ENTRY, "DMmcMediaDriverFlash::CheckDevice;aReqType=%d;this=%x", (TInt) aReqType, (TUint) this);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:cd:%d",aReqType));
 	TInt r=KErrNone;
 	if (!iCard->IsReady())
 	// Don't perform write/format operations on MMC ROM cards
 	else if (iMediaType==EMultiMediaROM && aReqType == EMReqTypeNormalWr)
 		r=KErrAccessDenied;
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:cd:%d", r));
-	return(r);
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_CHECKDEVICE_EXIT, this, r );
+	return r;
 	}
 void DMmcMediaDriverFlash::SessionEndCallBack(TAny* aMediaDriver)
 //
 // called by EPBUS when a single session has finished.  Queues DFC to launch
 // next session or to complete client request.
 //
 	{
+	OstTraceFunctionEntry0( DMMCMEDIADRIVERFLASH_SESSIONENDCALLBACK_ENTRY );
 	DMmcMediaDriverFlash& md = *static_cast<DMmcMediaDriverFlash*>(aMediaDriver);
 	__ASSERT_DEBUG(! md.iSessionEndDfc.Queued(), Panic(ESECBQueued));
 	md.iSessionEndDfc.Enque();
+	OstTraceFunctionExit0( DMMCMEDIADRIVERFLASH_SESSIONENDCALLBACK_EXIT );
 	}
 void DMmcMediaDriverFlash::SessionEndDfc(TAny* aMediaDriver)
 	{
 void DMmcMediaDriverFlash::DoSessionEndDfc()
 //
 // launch next session or complete client request
 //
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_DOSESSIONENDDFC_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:dsed:%d", CurrentRequest()));
+	OstTrace1( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DOSESSIONENDDFC_REQUEST, "Current Request=%d", CurrentRequest());
 	TInt r=KErrNone;
 	EndInCritical();
 		{
 		if (r != KErrNone)
 			InvalidateCache();
 		__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mdf:dsed:cmp:%d", r));
+		OstTrace1( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DOSESSIONENDDFC_COMPLETE, "Complete request; retval=%d", r);
 		CompleteRequest(r);
 		}
 	else
 		{
 		__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mdf:dsed:ncmp"));
-		}
+		OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_DOSESSIONENDDFC_NOT_COMPLETE, "Request not complete");
+		}
+	OstTraceFunctionExit1( DMMCMEDIADRIVERFLASH_DOSESSIONENDDFC_EXIT, this );
 	}
 void DMmcMediaDriverFlash::DataTransferCallBack(TAny* aMediaDriver)
 	{
+	OstTraceFunctionEntry0( DMMCMEDIADRIVERFLASH_DATATRANSFERCALLBACK_ENTRY );
 	DMmcMediaDriverFlash& md = *static_cast<DMmcMediaDriverFlash*>(aMediaDriver);
 	__ASSERT_DEBUG(! md.iDataTransferCallBackDfc.Queued(), Panic(EDBCBQueued));
 	md.iDataTransferCallBackDfc.Enque();
+	OstTraceFunctionExit0( DMMCMEDIADRIVERFLASH_DATATRANSFERCALLBACK_EXIT );
 	}
 void DMmcMediaDriverFlash::DataTransferCallBackDfc(TAny* aMediaDriver)
 	{
+	OstTraceFunctionEntry0( DMMCMEDIADRIVERFLASH_DATATRANSFERCALLBACKDFC_ENTRY );
 	DMmcMediaDriverFlash& md = *static_cast<DMmcMediaDriverFlash*>(aMediaDriver);
 	if (md.iDoPhysicalAddress)
 		{
 		if(md.CurrentRequest() == EMReqWrite)
 		else
 			{
 			md.DoReadDataTransferCallBack();
 			}
 		}
+	OstTraceFunctionExit0( DMMCMEDIADRIVERFLASH_DATATRANSFERCALLBACKDFC_EXIT );
 	}
 void DMmcMediaDriverFlash::DoPhysWriteDataTransferCallBack()
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_DOPHYSWRITEDATATRANSFERCALLBACK_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("++DMmcMediaDriverFlash::DoPhysWriteDataTransferCallBack()"));
 	TInt err = KErrNone;
 	if ( (iRdROB & KIPCSetup) || ((iReqEnd - iPhysEnd) < iBlkLen) )
 		iSession->MoreDataAvailable( (TInt)(iBlkLen >> KDiskSectorShift), (TUint8*)Epoc::LinearToPhysical((TLinAddr) iIntBuf), err);
 #else
 		iSession->MoreDataAvailable( (TInt)(iBlkLen >> KDiskSectorShift), iIntBuf, err);
 #endif
 		__KTRACE_OPT(KPBUSDRV, 	Kern::Printf("--iDoPhysicalAddress(KIPCSetup)"));
+		OstTraceFunctionExit1( DMMCMEDIADRIVERFLASH_DOPHYSWRITEDATATRANSFERCALLBACK_EXIT1, this );
 		return;
 		}
 	PrepareNextPhysicalFragment();
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("--DMmcMediaDriverFlash::DoPhysWriteDataTransferCallBack()"));
+	OstTraceFunctionExit1( DMMCMEDIADRIVERFLASH_DOPHYSWRITEDATATRANSFERCALLBACK_EXIT2, this );
 	}
 void DMmcMediaDriverFlash::DoPhysReadDataTransferCallBack()
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_DOPHYSREADDATATRANSFERCALLBACK_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, 	Kern::Printf("++DMmcMediaDriverFlash::DoPhysReadTransferCallBack()"));
 	TInt err = KErrNone;
 	if ((iRdROB & KIPCWrite) && !iSecondBuffer)
 #else
 		iSession->MoreDataAvailable( (TInt)(iIPCLen  >> KDiskSectorShift), iIntBuf, err);
 #endif
 		iSecondBuffer = ETrue;
 		__KTRACE_OPT(KPBUSDRV, 	Kern::Printf("--iDoPhysicalAddress(KIPCWrite)"));
+		OstTraceFunctionExit1( DMMCMEDIADRIVERFLASH_DOPHYSREADDATATRANSFERCALLBACK_EXIT1, this );
 		return;
 		}
 	PrepareNextPhysicalFragment();
 	__KTRACE_OPT(KPBUSDRV, 	Kern::Printf("--DMmcMediaDriverFlash::DoPhysReadTransferCallBack()"));
+	OstTraceFunctionExit1( DMMCMEDIADRIVERFLASH_DOPHYSREADDATATRANSFERCALLBACK_EXIT2, this );
 	}
 void DMmcMediaDriverFlash::DoWriteDataTransferCallBack()
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_DOWRITEDATATRANSFERCALLBACK_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("++DMmcMediaDriverFlash::DoWriteDataTransferCallBack()"));
 	TInt err = KErrNone;
 	// Advance current request progress...
 	// ...and signal that data is available to the PSL.
 	//
 	iSession->MoreDataAvailable(numBlocks, bufPtr, err);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("--DMmcMediaDriverFlash::DoWriteDataTransferCallBack()"));
+	OstTraceFunctionExit1( DMMCMEDIADRIVERFLASH_DOWRITEDATATRANSFERCALLBACK_EXIT, this );
 	}
 void DMmcMediaDriverFlash::DoReadDataTransferCallBack()
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_DOREADDATATRANSFERCALLBACK_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, 	Kern::Printf("++DMmcMediaDriverFlash::DoReadTransferCallBack()"));
 	TInt err = KErrNone;
 	const TUint32 doubleBufferSize = iMaxBufSize >> 1;
 			TUint8* bufPtr = iIntBuf + doubleBufferSize;
 			iSecondBuffer = EFalse;
 			iSession->MoreDataAvailable(numBlocks, bufPtr, KErrNone);
+			OstTraceFunctionExit1( DMMCMEDIADRIVERFLASH_DOREADDATATRANSFERCALLBACK_EXIT1, this );
 			return;
 			}
 		else
 			{
 			//
 	iSecondBuffer = iSecondBuffer ? (TBool)EFalse : (TBool)ETrue;
 	iSession->MoreDataAvailable(numBlocks, bufPtr, err);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("--DMmcMediaDriverFlash::DoDataTransferCallBack()"));
+	OstTraceFunctionExit1( DMMCMEDIADRIVERFLASH_DOREADDATATRANSFERCALLBACK_EXIT2, this );
 	}
 // ---- request management ----
 TInt DMmcMediaDriverFlash::EngageAndSetReadRequest(DMmcMediaDriverFlash::TMediaRequest aRequest)
 	{
-	return EngageAndSetRequest(aRequest, iReadCurrentInMilliAmps);
+	OstTraceExt2(TRACE_FLOW, DMMCMEDIADRIVERFLASH_ENGAGEANDSETREADREQUEST_ENTRY, "DMmcMediaDriverFlash::EngageAndSetReadRequest;aRequest=%d;this=%x", (TInt) aRequest, (TUint) this);
+	TInt r = EngageAndSetRequest(aRequest, iReadCurrentInMilliAmps);
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_ENGAGEANDSETREADREQUEST_EXIT, this, r );
+	return r;
 	}
 TInt DMmcMediaDriverFlash::EngageAndSetWriteRequest(DMmcMediaDriverFlash::TMediaRequest aRequest)
 	{
-	return EngageAndSetRequest(aRequest, iWriteCurrentInMilliAmps);
+	OstTraceExt2(TRACE_FLOW, DMMCMEDIADRIVERFLASH_ENGAGEANDSETWRITEREQUEST_ENTRY, "DMmcMediaDriverFlash::EngageAndSetReadRequest;aRequest=%d;this=%x", (TInt) aRequest, (TUint) this);
+	TInt r = EngageAndSetRequest(aRequest, iWriteCurrentInMilliAmps);
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_ENGAGEANDSETWRITEREQUEST_EXIT, this, r );
+	return r;
 	}
 TInt DMmcMediaDriverFlash::EngageAndSetRequest(DMmcMediaDriverFlash::TMediaRequest aRequest, TInt aCurrent)
 //
 // In WINS, all of the processing, including the callbacks, is done when Engage() is called,
 // so the request value must be set up in advanced.  Both the request and the current are
 // cleared in the corresponding call to CompleteRequest().
 //
 	{
+	OstTraceExt3(TRACE_FLOW, DMMCMEDIADRIVERFLASH_ENGAGEANDSETREQUEST_ENTRY, "DMmcMediaDriverFlash::EngageAndSetRequest;aRequest=%d;aCurrent=%d;this=%x", (TInt) aRequest, aCurrent, (TUint) this);
 	__ASSERT_DEBUG(iSession != NULL, Panic(ECFSessPtrNull));
 	iMedReq = aRequest;
 	SetCurrentConsumption(aCurrent);
 		if (!iCard->IsReady())
 			r=KErrNotReady; // If media change - return not ready rather than anything else.
 		EndInCritical();
 		}
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_ENGAGEANDSETREQUEST_EXIT, this, r );
 	return r;
 	}
 void DMmcMediaDriverFlash::CompleteRequest(TInt aReason)
 //
 // completes the specified request
 //
 	{
+	OstTraceFunctionEntryExt( DMMCMEDIADRIVERFLASH_COMPLETEREQUEST_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("=mmd:cr0x%08x,%d", iCurrentReq, aReason));
 	iMedReq = EMReqIdle;
 	SetCurrentConsumption(KIdleCurrentInMilliAmps);
 #endif		// __TEST_PAGING_MEDIA_DRIVER__
 #endif		// __DEMAND_PAGING__
 		iCurrentReq=NULL;
 		DMediaDriver::Complete(*pR,aReason);
 		}
+	OstTraceFunctionExit1( DMMCMEDIADRIVERFLASH_COMPLETEREQUEST_EXIT, this );
 	}
 TInt DMmcMediaDriverFlash::Caps(TLocDrv& aDrive, TLocalDriveCapsV6& aInfo)
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_CAPS_ENTRY, this );
 	// Fill buffer with current media caps.
 	aInfo.iType = EMediaHardDisk;
 	aInfo.iConnectionBusType = EConnectionBusInternal;
 	aInfo.iDriveAtt = KDriveAttLocal;
 	aInfo.iMediaAtt	= KMediaAttFormattable;
 		{
 		TUint16 reservedSectors;
 		TMBRPartitionEntry dummy;	// Not used here
 		const TInt r = GetMediaDefaultPartitionInfo(dummy, reservedSectors, iCard);
 		if(r != KErrNone)
+		    {
+			OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_CAPS_EXIT1, this, r );
 			return r;
+		    }
 		aInfo.iFormatInfo.iReservedSectors = reservedSectors;
 		aInfo.iExtraInfo = ETrue;
 		}
 		aInfo.iMediaAtt&= ~KMediaAttFormattable;
 		}
 	// Must return KErrCompletion to indicate that this
 	// is a synchronous version of the function
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_CAPS_EXIT2, this, KErrCompletion );
 	return KErrCompletion;
 	}
 // ---- cache ----
 // return value is not KErrNone.
 //
 // This function is linear in the number of blocks in the cache.
 //
 	{
+	OstTraceFunctionEntryExt( DMMCMEDIADRIVERFLASH_READDATAUNTILCACHEEXHAUSTED_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:rdc:%x,%x", iReqCur, iReqEnd));
+	OstTraceExt2( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_READDATAUNTILCACHEEXHAUSTED, "iReqCur=0x%x; iReqEnd=0x%x", (TUint) iReqCur, (TUint) iReqEnd );
 	if ( iCurrentReq->IsPhysicalAddress()
 #if defined(__DEMAND_PAGING__) && !defined(__WINS__)
 	     || DMediaPagingDevice::PageInRequest(*iCurrentReq)
 #endif //DEMAND_PAGING
 )
 		{
 		*aAllDone = EFalse;
+		OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_READDATAUNTILCACHEEXHAUSTED_EXIT1, this, KErrNone );
 		return KErrNone;
 		}
 	TInt64 physStart = iReqCur & ~iBlkMsk;
 	TInt64 physEnd = Min(physStart + iMaxBufSize, (iReqEnd + iBlkMsk) & ~iBlkMsk);
 		}
 	*aAllDone = (iReqCur >= iReqEnd);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:rdc:%d,%d", *aAllDone, r));
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_READDATAUNTILCACHEEXHAUSTED_EXIT2, this, r );
 	return r;
 	}
 TInt DMmcMediaDriverFlash::WriteDataToUser(TUint8* aBufPtr)
 //
 // write the data from the most recent read operation to the user descriptor
 //
 	{
+	OstTraceFunctionEntryExt( DMMCMEDIADRIVERFLASH_WRITEDATATOUSER_ENTRY, this );
 	TInt r = KErrNotSupported;
 	// get range of data to read out of internal buffer
 	TInt len = I64LOW(UMin(iPhysEnd, iReqEnd) - iReqCur);
 	TPtrC8 extrView(aBufPtr, len);
 	// write data from internal buffer
 	TUint usrOfst = I64LOW(iReqCur - iReqStart);
+	OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_WRITEDATATOUSER_LATENCY1, "Begin writing user data" );
 #if defined(__DEMAND_PAGING__) && !defined(__WINS__)
 	if (DMediaPagingDevice::PageInRequest(*iCurrentReq))
 		r=iCurrentReq->WriteToPageHandler((TUint8 *)(&extrView[0]), len, usrOfst);
 	else
 #endif	// __DEMAND_PAGING__
 		r = iCurrentReq->WriteRemote(&extrView,usrOfst);
+	OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_WRITEDATATOUSER_LATENCY2, "End writing user data" );
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_WRITEDATATOUSER_EXIT, this, r );
 	return r;
 	}
 TInt DMmcMediaDriverFlash::ReadDataFromUser(TDes8& aDes, TInt aOffset)
 	{
+	OstTraceExt2(TRACE_FLOW, DMMCMEDIADRIVERFLASH_READDATAFROMUSER_ENTRY ,"DMmcMediaDriverFlash::ReadDataFromUser;aOffset=%d;this=%x", aOffset, (TUint) this);
+	TInt r = KErrNotSupported;
 #ifndef __WINS__
 	if (DMediaPagingDevice::PageOutRequest(*iCurrentReq))
-		return iCurrentReq->ReadFromPageHandler((TAny*) aDes.Ptr(), aDes.MaxLength(), aOffset);
+	    {
+		r = iCurrentReq->ReadFromPageHandler((TAny*) aDes.Ptr(), aDes.MaxLength(), aOffset);
+		OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_READDATAFROMUSER_EXIT1, this, r );
+		return r;
+	    }
 	else
 #endif // #ifndef __WINS__
-		return iCurrentReq->ReadRemote(&aDes, aOffset);
+		r = iCurrentReq->ReadRemote(&aDes, aOffset);
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_READDATAFROMUSER_EXIT2, this, r );
+	return r;
 	}
 TInt DMmcMediaDriverFlash::AdjustPhysicalFragment(TPhysAddr &aPhysAddr, TInt &aPhysLength)
 //
 // Retrieve next Physical memory fragment and adjust the start pointer and length with
 // respect to the set offset {iFragOfset}.
 // Note the offset may encompass multiple memory fragments.
 //
 	{
+	OstTraceExt3(TRACE_FLOW, DMMCMEDIADRIVERFLASH_ADJUSTPHYSICALFRAGMENT_ENTRY, "DMmcMediaDriverFlash::AdjustPhysicalFragment;aPhysAddr=%x;aPhysLength=%d;this=%x", (TUint) aPhysAddr, aPhysLength, (TUint) this);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:APF"));
 	TInt err = KErrNone;
 	TInt offset = iFragOfset;
 	do
 		{
 		err = iCurrentReq->GetNextPhysicalAddress(aPhysAddr, aPhysLength);
 		if (err != KErrNone)
+		    {
+			OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_ADJUSTPHYSICALFRAGMENT_EXIT1, this, err );
 			return err;
+		    }
 		if (offset >= aPhysLength) // more offset than in this physical chunk
 			{
 			offset -= aPhysLength;
 			}
 	iFragOfset = 0; // reset offset now complete
 	if (aPhysAddr == 0)
 		{
+		OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_ADJUSTPHYSICALFRAGMENT_EXIT2, this, KErrNoMemory );
 		return KErrNoMemory;
 		}
 #ifdef _DEBUG
 	// DMAHelper ensures memory is dma aligned
 	if ( (aPhysAddr & (iSocket->DmaAlignment()-1) ) )
 		{
 		__KTRACE_OPT(KPBUSDRV, Kern::Printf("mmd:lr:Memory Fragment Not Word Aligned!"));
+		OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_ADJUSTPHYSICALFRAGMENT_DMA, "Memory fragment not word aligned");
 		Panic(ENotDMAAligned);
 		}
 #endif	//_DEBUG
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:APF physAddr(0x%x), physLength(%d)",aPhysAddr, aPhysLength));
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_ADJUSTPHYSICALFRAGMENT_EXIT3, this, err );
 	return err;
 	}
 TInt DMmcMediaDriverFlash::PrepareFirstPhysicalFragment(TPhysAddr &aPhysAddr, TInt &aPhysLength, TUint32 aLength)
 //
 // Retrieves the first Physical memory fragment and determines the type of the next transfer
 // Next transfer may either be the last block (end not block aligned) or a block may straddle
 // memory fragments.
 //
 	{
+	OstTraceExt4(TRACE_FLOW, DMMCMEDIADRIVERFLASH_PREPAREFIRSTPHYSICALFRAGMENT_ENTRY, "DMmcMediaDriverFlash::PrepareFirstPhysicalFragment;aPhysAddr=%x;aPhysLength=%d;aLength=%x;this=%x", (TUint) aPhysAddr, aPhysLength, (TUint) aLength, (TUint) this);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:PFPF"));
 	TInt r = KErrNone;
 	r = AdjustPhysicalFragment(aPhysAddr, aPhysLength);
 		{
 		TUint len = I64LOW(iReqEnd & iBlkMsk);
 		if ( ((TUint32)aPhysLength >= aLength) && len )
 			{
 			__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:PFPF-end block"));
+			OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_PREPAREFIRSTPHYSICALFRAGMENT_EB, "End block");
 			//next iteration will be an IPC for the end block
 			//There is enough space in physical memory to fit
 			//the extended read, but exceeds boundary for this request.
 			iIPCLen = len;
 			iRdROB |= KIPCSetup; // IPC setup for next iteration
 			}
 		if (aPhysLength & iBlkMsk)
 			{
 			__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:PFPF-straddles boundary"));
+			OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_PREPAREFIRSTPHYSICALFRAGMENT_SB, "Straddles boundary");
 			// block must be straddling a fragment boundary
 			// Next iteration must be an IPC
 			iRdROB |= KIPCSetup;
 			// Calculate the offset into the next memory block
 			aPhysLength &= ~iBlkMsk;
 			}
 		}
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:PFPF err(%d), physAddr(0x%x), physLength(%d)",r, aPhysAddr, aPhysLength));
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_PREPAREFIRSTPHYSICALFRAGMENT_EXIT, this, r );
 	return r;
 	}
 void DMmcMediaDriverFlash::PrepareNextPhysicalFragment()
 // Retrieves next Physical memory fragment and determines the type of the next transfer
 // Next transfer may either be the last block (end not block aligned) or a block may straddle
 // memory fragments.
 //
 	{
+	OstTraceFunctionEntry0( DMMCMEDIADRIVERFLASH_PREPARENEXTPHYSICALFRAGMENT_ENTRY );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:PNPF"));
 	TInt err = KErrNone;
 	TPhysAddr physAddr = 0;
 	TInt physLength = 0;
 			//Last physical transfer ...
 			TUint len = I64LOW(iReqEnd & iBlkMsk);
 			if (len)
 				{
 				__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:PNPF-end block"));
+				OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_PREPARENEXTPHYSICALFRAGMENT_EB, "End block" );
 				// end point not block aligned!
 				// next iteration must be an IPC call
 				iRdROB |= KIPCSetup;
 				iIPCLen = len;
 				physLength -= len;
 			}
 		if (physLength & iBlkMsk)
 			{
 			__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:PNPF-straddles boundary"));
+			OstTrace0( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_PREPARENEXTPHYSICALFRAGMENT_SB, "Straddles boundary" );
 			// block must be straddling a fragment boundary
 			// Next iteration must be an IPC
 			iRdROB |= KIPCSetup;
 			// Calculate the offset into the next memory block
 		}
 	iSession->MoreDataAvailable( (physLength  >> KDiskSectorShift), (TUint8*) physAddr, err);
 	iSecondBuffer = EFalse;
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:PNPF"));
+	OstTraceFunctionExit0( DMMCMEDIADRIVERFLASH_PREPARENEXTPHYSICALFRAGMENT_EXIT );
 	}
 TUint8* DMmcMediaDriverFlash::ReserveReadBlocks(TInt64 aStart, TInt64 aEnd, TUint32* aLength)
 //
 // Assume the cache has been drained before this function is called and so
 // either aEnd - aStart, or enough blocks such that the next block to read
 // is already available in the cache, and so will be read when
 // ReadDataUntilCacheExhausted() is called from the callback DFC.
 //
 	{
+	OstTraceFunctionEntryExt( DMMCMEDIADRIVERFLASH_RESERVEREADBLOCKS_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:rrb:%lx,%lx", aStart, aEnd));
 	__ASSERT_DEBUG((aStart & iBlkMsk) == 0, Panic(ERRBStAlign));
 	__ASSERT_DEBUG(TotalSizeInBytes() > aStart, Panic(ERRBStPos));
 	__ASSERT_DEBUG(aEnd > aStart, Panic(ERRBNotPositive));
 	iLstUsdCchEnt = startIndex + blkCnt - 1;
 	if (blkCnt < 1) blkCnt = 1; //RBW required < 1 block to be read
+	OstTraceExt2( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_RESERVEREADBLOCKS_RANGE, "blocksInRange=%d; blkCnt=%d", blocksInRange, blkCnt );
 	TUint32 lengthInBytes = blkCnt << iBlkLenLog2;
 	*aLength = lengthInBytes;
 	MarkBlocks(aStart, aStart + lengthInBytes, startIndex);
 	raby = IdxToCchMem(startIndex);
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:rrb:%x", (TUint32) raby));
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_RESERVEREADBLOCKS_EXIT, this, ( TUint )( raby ) );
 	return raby;
 	}
 TUint8* DMmcMediaDriverFlash::ReserveWriteBlocks(TInt64 aStart, TInt64 aEnd, TUint* aRBM)
 //
 // aStart and aEnd are not necessarily block aligned - the function uses alignment
 // information to minimize RBMs.
 //
 	{
+	OstTraceFunctionEntryExt( DMMCMEDIADRIVERFLASH_RESERVEWRITEBLOCKS_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:rwb:%lx,%lx", aStart, aEnd));
 	TInt64 physStart = aStart & ~iBlkMsk;
 	TInt64 physEnd = (aEnd + iBlkMsk) & ~iBlkMsk;
 	const TBool firstPartial = (aStart & iBlkMsk) != 0;
 	const TBool lastPartial  = (aEnd & iBlkMsk)   != 0;
 	const TInt blkCnt = I64LOW((physEnd - physStart) >> iBlkLenLog2);
+	OstTrace1( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_RESERVEWRITEBLOCKS_RANGE, "blkCnt=%d", blkCnt );
 	TBool startUsed = EFalse;
 	TBool endUsed   = EFalse;
 	TUint8* raby = NULL;
 			if ( (firstPartial || lastPartial) && blkCnt <= 2)
 				{
 				//Physical addressing not to be used.
 				//more efficent to use local Cache copying
 				iDoPhysicalAddress = EFalse;
+				OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_RESERVEWRITEBLOCKS_EXIT1, this, ( TUint )( raby ) );
 				return raby;
 				}
 			else
 				{
 				raby = iMinorBuf;
 					if (lastPartial && !lastPres)
 						*aRBM |= KWtRBMLst;
 					}
+				OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_RESERVEWRITEBLOCKS_EXIT2, this, ( TUint )( raby ) );
 				return raby;
 				}
 			} // if (iDoPhysicalAddress)
 		if (!firstUsable && !lastUsable)
 			iDoLastRMW = ETrue;
 		}
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:rwb:%x", (TUint32) raby));
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_RESERVEWRITEBLOCKS_EXIT3, this, ( TUint )( raby ) );
 	return raby;
 	}
 void DMmcMediaDriverFlash::MarkBlocks(TInt64 aStart, TInt64 aEnd, TInt aStartIndex)
 //
 // mark range of blocks for media range.  If existing cache entries for any part of
 // the cache are already in the buffer they are invalidated.
 //
 	{
+	OstTraceFunctionEntryExt( DMMCMEDIADRIVERFLASH_MARKBLOCKS_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("=mmd:mb:%lx,%lx,%d", aStart, aEnd, aStartIndex));
 	__ASSERT_DEBUG(TotalSizeInBytes() > aStart, Panic(EMBStPos));
 	__ASSERT_DEBUG((aStart & iBlkMsk) == 0, Panic(EMBStAlign));
 	__ASSERT_DEBUG(aEnd > aStart, Panic(EMBNotPositive));
 		if (iCachedBlocks[i] >= aStart && iCachedBlocks[i] < aEnd)
 			iCachedBlocks[i] = KInvalidBlock;
 		}
 	TInt blkCnt = I64LOW((aEnd - aStart) >> iBlkLenLog2);
+	OstTrace1( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_MARKBLOCKS_RANGE, "blkCnt=%d", blkCnt );
 	for (i = aStartIndex; i < aStartIndex + blkCnt; ++i)
 		iCachedBlocks[i] = aStart + (static_cast<TUint32>(i - aStartIndex) << iBlkLenLog2);
 	for (i = aStartIndex + blkCnt; i < iBlocksInBuffer; ++i)
 		{
 		if (iCachedBlocks[i] >= aStart && iCachedBlocks[i] < aEnd)
 			iCachedBlocks[i] = KInvalidBlock;
 		}
 	__ASSERT_CACHE(CacheInvariant(), Panic(EMBCchInvPost));
+	OstTraceFunctionExit1( DMMCMEDIADRIVERFLASH_MARKBLOCKS_EXIT, this );
 	}
 void DMmcMediaDriverFlash::BuildGammaArray(TInt64 aStart, TInt64 aEnd)
 //
 // aStart + iBlkLen, and so on.  Building an array here means that all of
 // the available cached entries can be found in linear time instead of
 // quadratically searching through the array for each block.
 //
 	{
+	OstTraceFunctionEntryExt( DMMCMEDIADRIVERFLASH_BUILDGAMMAARRAY_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("=mmd:bga:%lx,%lx", aStart, aEnd));
 	__ASSERT_DEBUG(TotalSizeInBytes() > aStart, Panic(EBGAStPos));
 	__ASSERT_DEBUG((aStart & iBlkMsk) == 0, Panic(EBGAStAlign));
 	__ASSERT_DEBUG(aEnd > aStart, Panic(EBGANotPositive));
 	__ASSERT_DEBUG(aEnd - aStart <= (TInt64) iMaxBufSize, Panic(EBGAOverflow));
 	__ASSERT_CACHE(CacheInvariant(), Panic(EBGACchInv));
 	// KNoCacheBlock = (0xff) x 4
 	TUint blocksInRange = I64LOW((aEnd - aStart) >> iBlkLenLog2);
+	OstTrace1( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_BUILDGAMMAARRAY_RANGE, "blocksInRange=%d", blocksInRange );
 	memset(iGamma, 0xff, sizeof(*iGamma) * blocksInRange);
 	TInt64 blkAddr = 0;
 	for (TInt i = 0; ( (blocksInRange > 0 ) && (i < iBlocksInBuffer) ); ++i)
 		{
 			{
 			iGamma[I64LOW((blkAddr - aStart) >> iBlkLenLog2)] = i;
 			blocksInRange--;
 			}
 		}
+	OstTraceFunctionExit1( DMMCMEDIADRIVERFLASH_BUILDGAMMAARRAY_EXIT, this );
 	}
 void DMmcMediaDriverFlash::InvalidateCache()
 	{
+	OstTraceFunctionEntry0( DMMCMEDIADRIVERFLASH_INVALIDATECACHE1_ENTRY );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("=mmd:ich"));
 	// KInvalidBlock = (0xff) x 4
 	memset(iCachedBlocks, 0xff, sizeof(*iCachedBlocks) * iBlocksInBuffer);
+	OstTraceFunctionExit0( DMMCMEDIADRIVERFLASH_INVALIDATECACHE1_EXIT );
 	}
 // Invalidate any cache entries from aStart to aEnd
 // This is for DMA writes and is to prevent the cache becoming inconsistent with the media.
 void DMmcMediaDriverFlash::InvalidateCache(TInt64 aStart, TInt64 aEnd)
 	{
+	OstTraceFunctionEntryExt( DMMCMEDIADRIVERFLASH_INVALIDATECACHE2_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("=mmd:ich:%lx,%lx", aStart, aEnd));
 	__ASSERT_DEBUG(TotalSizeInBytes() > aStart, Panic(EBGAStPos));
 	__ASSERT_DEBUG(aEnd > aStart, Panic(EBGANotPositive));
 	__ASSERT_DEBUG(TotalSizeInBytes() >= aEnd, Panic(EBGAEndPos));
 	const TInt blkCnt = I64LOW((aStart - aEnd) >> iBlkLenLog2);
+	OstTrace1( TRACE_INTERNALS, DMMCMEDIADRIVERFLASH_INVALIDATECACHE_RANGE, "blocksInRange=%d", blkCnt );
 	__ASSERT_CACHE(CacheInvariant(), Panic(EBGACchInv));
 	TInt64 endBlk = (blkCnt == 0) ? (aStart+iBlkLen) : aEnd;
 		{
 		const TInt64 blkAddr = iCachedBlocks[i];
 		if (blkAddr >= aStart && blkAddr < endBlk)
 			iCachedBlocks[i] = KInvalidBlock;
 		}
+	OstTraceFunctionExit1( DMMCMEDIADRIVERFLASH_INVALIDATECACHE2_EXIT, this );
 	}
 TUint8* DMmcMediaDriverFlash::IdxToCchMem(TInt aIdx) const
 	{
+	OstTraceFunctionEntryExt( DMMCMEDIADRIVERFLASH_IDXTOCCHMEM_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("=mmd:icm:%d", aIdx));
 	__ASSERT_DEBUG(aIdx >= 0, Panic(EICMNegative));
 	__ASSERT_DEBUG(aIdx < iBlocksInBuffer, Panic(EICMOverflow));
+	OstTraceFunctionExit1( DMMCMEDIADRIVERFLASH_IDXTOCCHMEM_EXIT, this );
 	return &iCacheBuf[aIdx << iBlkLenLog2];
 	}
 TInt DMmcMediaDriverFlash::CchMemToIdx(TUint8* aMemP) const
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_CCHMEMTOIDX_ENTRY, this );
 	__ASSERT_DEBUG((aMemP >= iCacheBuf) && (aMemP < iCacheBuf + (iBlocksInBuffer << iBlkLenLog2)), Panic(ECMIOverflow));
 	return((aMemP - iCacheBuf) >> iBlkLenLog2);
 	}
 // check each cache entry refers to a valid block and that no two
 // entries cover the same block.  This algorithm is quadratic in
 // the cache length.
 //
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_CACHEINVARIANT_ENTRY, this );
 	for (TInt i = 0; i < iBlocksInBuffer; ++i)
 		{
 		if (iCachedBlocks[i] == KInvalidBlock)
 			continue;
 			if (iCachedBlocks[i] == iCachedBlocks[j])
 				return EFalse;
 			}
 		}
+	OstTraceFunctionExit1( DMMCMEDIADRIVERFLASH_CACHEINVARIANT_EXIT, this );
 	return ETrue;
 	}
 #endif
 void DMmcMediaDriverFlash::NotifyPowerDown()
 	{
+	OstTraceFunctionEntry0( DMMCMEDIADRIVERFLASH_NOTIFYPOWERDOWN_ENTRY );
 	__KTRACE_OPT(KPBUSDRV,Kern::Printf(">Mmc:NotifyPowerDown"));
 	iSessionEndDfc.Cancel();
 	iDataTransferCallBackDfc.Cancel();
 	if (iSession)
 		iStack->CancelSession(iSession);
 	CompleteRequest(KErrNotReady);
 	iMedReq = EMReqIdle;
+	OstTraceFunctionExit0( DMMCMEDIADRIVERFLASH_NOTIFYPOWERDOWN_EXIT );
 	}
 void DMmcMediaDriverFlash::NotifyEmergencyPowerDown()
 	{
+	OstTraceFunctionEntry0( DMMCMEDIADRIVERFLASH_NOTIFYEMERGENCYPOWERDOWN_ENTRY );
 	__KTRACE_OPT(KPBUSDRV,Kern::Printf(">Ata:NotifyEmergencyPowerDown"));
 	iSessionEndDfc.Cancel();
 	iDataTransferCallBackDfc.Cancel();
 	if (iSession)
 		iStack->CancelSession(iSession);
 	CompleteRequest(r);
 	iMedReq = EMReqIdle;
+	OstTraceFunctionExit0( DMMCMEDIADRIVERFLASH_NOTIFYEMERGENCYPOWERDOWN_EXIT );
 	}
 TInt DMmcMediaDriverFlash::Request(TLocDrvRequest& aRequest)
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_REQUEST_ENTRY, this );
 	__KTRACE_OPT(KLOCDRV,Kern::Printf("MmcMd:Req %08x id %d",&aRequest,aRequest.Id()));
 	TInt r=KErrNotSupported;
 	TInt id=aRequest.Id();
+	OstTraceDefExt2( OST_TRACE_CATEGORY_RND, TRACE_REQUEST, DMMCMEDIADRIVERFLASH_REQUEST_ID, "Request=0x%08x; Request ID=%d", (TUint) &aRequest, id);
 #if defined (__TEST_PAGING_MEDIA_DRIVER__)
 	DThread* client=aRequest.Client();
 	__KTRACE_OPT(KLOCDPAGING,Kern::Printf("Client:0x%08x",client));
+	OstTraceDef1( OST_TRACE_CATEGORY_RND, TRACE_REQUEST, DMMCMEDIADRIVERFLASH_REQUEST_CLIENT, "Request client=0x%08x", (TUint) client);
 #endif // __TEST_PAGING_MEDIA_DRIVER__
 	// First handle requests that can be handled without deferring
 	if(id==DLocalDrive::ECaps)
 		{
 		TLocDrv& drive = *aRequest.Drive();
 		r = Caps(drive, c);
 		c.iSize = drive.iPartitionLen;
 		c.iPartitionType = drive.iPartitionType;
 		c.iHiddenSectors = (TUint) (drive.iPartitionBaseAddr >> KDiskSectorShift);
+		OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_REQUEST_EXIT1, this, r );
 		return r;
 		}
 	// All other requests must be deferred if a request is currently in progress
 	if (iCurrentReq)
 			iMmcStats.iReqNormal++;
 #endif // __TEST_PAGING_MEDIA_DRIVER__
 		// a request is already in progress, so hold on to this one
 		__KTRACE_OPT(KLOCDRV,Kern::Printf("MmcMd:Req %08x ret 1",&aRequest));
+		OstTraceDef1( OST_TRACE_CATEGORY_RND, TRACE_REQUEST, DMMCMEDIADRIVERFLASH_REQUEST_IN_PROGRESS, "Request in progress=0x%08x", (TUint) &aRequest);
+		OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_REQUEST_EXIT2, this, KMediaDriverDeferRequest );
 		return KMediaDriverDeferRequest;
 		}
 	else
 		{
 		iCurrentReq=&aRequest;
 #if defined(__DEMAND_PAGING__)
 			case DMediaPagingDevice::ERomPageInRequest:
 				__KTRACE_OPT(KLOCDPAGING,Kern::Printf("DMediaDriverFlash::Request(ERomPageInRequest)"));
 				BTraceContext8(BTrace::EPagingMedia,BTrace::EPagingMediaPagingMedDrvBegin,MEDIA_DEVICE_MMC,iCurrentReq);
+				OstTraceDef0( OST_TRACE_CATEGORY_RND, TRACE_REQUEST, DMMCMEDIADRIVERFLASH_REQUEST_ROM_PAGE_IN, "ROM page-in request");
 				r=DoRead();
 				break;
 			case DMediaPagingDevice::ECodePageInRequest:
 				__KTRACE_OPT(KLOCDPAGING,Kern::Printf("DMediaDriverFlash::Request(ECodePageInRequest)"));
 				BTraceContext8(BTrace::EPagingMedia,BTrace::EPagingMediaPagingMedDrvBegin,MEDIA_DEVICE_MMC,iCurrentReq);
+				OstTraceDef0( OST_TRACE_CATEGORY_RND, TRACE_REQUEST, DMMCMEDIADRIVERFLASH_REQUEST_CODE_PAGE_IN, "Code page-in request");
 				r=DoRead();
 				break;
 #endif	// __DEMAND_PAGING__
 			case DLocalDrive::EQueryDevice:
 			case DLocalDrive::ERead:
 				r=DoRead();
 				break;
 			case DLocalDrive::EWrite:
 				if (readOnly)
+				    {
+					OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_REQUEST_EXIT3, this, KErrNotSupported );
 					return KErrNotSupported;
+				    }
 				r=DoWrite();
 				break;
 			case DLocalDrive::EFormat:
 				if (readOnly)
+				    {
+					OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_REQUEST_EXIT4, this, KErrNotSupported );
 					return KErrNotSupported;
+				    }
 				r=DoFormat();
 				break;
 #if defined __TEST_PAGING_MEDIA_DRIVER__
 			case DLocalDrive::EControlIO:
 		iMedReq = EMReqIdle;
 		iCurrentReq=NULL;
 		SetCurrentConsumption(KIdleCurrentInMilliAmps);
 		}
+	OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_REQUEST_EXIT5, this, r );
 	return r;
 	}
 void DMmcMediaDriverFlash::Disconnect(DLocalDrive* aLocalDrive, TThreadMessage* aMsg)
 	{
+	OstTraceFunctionEntry1( DMMCMEDIADRIVERFLASH_DISCONNECT_ENTRY, this );
 	// Complete using the default implementation
 	DMediaDriver::Disconnect(aLocalDrive, aMsg);
+	OstTraceFunctionExit1( DMMCMEDIADRIVERFLASH_DISCONNECT_EXIT, this );
 	}
 #ifdef _DEBUG_CACHE
 TUint8* DMmcMediaDriverFlash::GetCachedBlock(TInt64 aMdAddr)
 //
 // the cache.  It should not be used for general block retrieval.
 // If there are m blocks in the cache, and n in the requested range,
 // this function is o(mn), whereas BuildGammaArray() is theta(m).
 //
 	{
+	OstTraceFunctionEntryExt( DMMCMEDIADRIVERFLASH_GETCACHEDBLOCK_ENTRY, this );
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf(">mmd:gcb:%lx", aMdAddr));
 	__ASSERT_DEBUG((aMdAddr & iBlkMsk) == 0, Panic(EGCBAlign));
 	__ASSERT_DEBUG(TotalSizeInBytes() > aMdAddr, Panic(EGCBPos));
 	__ASSERT_CACHE(CacheInvariant(), Panic(EGCBCchInv));
 		{
 		if (iCachedBlocks[i] == aMdAddr)
 			{
 			TUint8* raby = IdxToCchMem(i);
 			__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:gcb:%x", (TUint32) raby));
+			OstTraceFunctionExitExt( DMMCMEDIADRIVERFLASH_GETCACHEDBLOCK_EXIT1, this, ( TUint )( raby ) );
 			return raby;
 			}
 		}
 	__KTRACE_OPT(KPBUSDRV, Kern::Printf("<mmd:gcb:0"));
+	OstTraceFunctionExit1( DMMCMEDIADRIVERFLASH_GETCACHEDBLOCK_EXIT2, this );
 	return 0;
 	}
 #endif // _DEBUG_CACHE

changeset 13	46fffbe7b5a7
parent 10	36bfc973b146
child 28	5b5d147c7838