diff -r 630d2f34d719 -r 07a122eea281 telephonyprotocols/rawipnif/src/RawIPFlow.cpp --- a/telephonyprotocols/rawipnif/src/RawIPFlow.cpp Tue Aug 31 16:23:08 2010 +0300 +++ b/telephonyprotocols/rawipnif/src/RawIPFlow.cpp Wed Sep 01 12:40:21 2010 +0100 @@ -21,12 +21,6 @@ @file */ - -#include "OstTraceDefinitions.h" -#ifdef OST_TRACE_COMPILER_IN_USE -#include "RawIPFlowTraces.h" -#endif - #include #include #include @@ -52,13 +46,15 @@ static const TUint16 KTcpDumpLinkType = 12; #endif -CRawIPFlow::CRawIPFlow(CSubConnectionFlowFactoryBase& aFactory, const TNodeId& aSubConnId, CProtocolIntfBase* aProtocolIntf) +CRawIPFlow::CRawIPFlow(CSubConnectionFlowFactoryBase& aFactory, const TNodeId& aSubConnId, CProtocolIntfBase* aProtocolIntf, CBttLogger* aTheLogger) /** * Constructor. * * @param aFactory Reference to the factory which created this object. + * @param aTheLogger The logging object, ownership is passed to this object */ : CSubConnectionFlowBase(aFactory, aSubConnId, aProtocolIntf), + iTheLogger(aTheLogger), iInitError(KErrNone), iStarted(EFalse), iStopping(EFalse) @@ -74,9 +70,9 @@ * @param aName The name of the NIF (unused) */ { - OstTraceDef1(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_CONSTRUCTL_1, "CRawIPFlow %08x:\tConstructL()", this); + _LOG_L1C2(_L8("CRawIPFlow %08x:\tConstructL()"), this); iBinderControl = new (ELeave) TBinderControlProxy(*this); - iBcaController = CBcaIoController::NewL(*this); + iBcaController = CBcaIoController::NewL(*this, iTheLogger); } CRawIPFlow::~CRawIPFlow() @@ -86,6 +82,8 @@ { // Note that we don't delete iBinder because it's not owned by us. delete iBcaController; + // This class also deletes the logging object + delete iTheLogger; ASSERT(iBinder == NULL); @@ -107,7 +105,7 @@ { ASSERT(iStarting==EFalse); iStarting = ETrue; - OstTraceDef1(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_STARTFLOWL_1, "CRawIPFlow %08x:\tStartFlowL()", this); + _LOG_L1C2(_L8("CRawIPFlow %08x:\tStartFlowL()"), this); // If there were any errors during earlier processing of the ProvisionConfig message // then send an Error message in response to the StartFlow (because ProvisionConfig @@ -142,13 +140,13 @@ _LIT8(KTimeFormat, "%08X"); TUint32 counter = User::FastCounter(); logFileName.Format(KTimeFormat, counter); - - TRAPD(err,__PACKETLOG_NEWL(KTcpDumpFirstTag, logFileName, CPacketLogger::ETcpDump, KTcpDumpLinkType)); - if (err) - { - OstTraceDef0(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_STARTFLOWL_2, "Trapped leave from __PACKETLOG_NEWL"); - } - + + TRAPD(err,__PACKETLOG_NEWL(KTcpDumpFirstTag, logFileName, CPacketLogger::ETcpDump, KTcpDumpLinkType)); + if (err) + { + _LOG_L1C1(_L8("Trapped leave from __PACKETLOG_NEWL")); + } + const TUint KLogTextLen = KModemNameLen+KTimeStampLen+30; TBuf8 logText; _LIT8(KLogTimeText, "TcpDump log file time stamp:"); @@ -157,7 +155,7 @@ logText.Append(logFileName); logText.Append(KLogModemText); logText.Append(modemName); - OstTraceDefExt1(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_STARTFLOWL_3, "%s", logText); + _LOG_L1C1(logText); #endif } @@ -169,7 +167,7 @@ * ready to go. */ { - OstTraceDef1(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_LINKLAYERUP_1, "CRawIPFlow %08x:\tLinkLayerUp()", this); + _LOG_L1C2(_L8("CRawIPFlow %08x:\tLinkLayerUp()"), this); iLastRequestOriginator.ReplyTo(Id(), TCFDataClient::TStarted().CRef()); @@ -188,10 +186,9 @@ * @param aError An error code to propagate to NifMan */ { - OstTraceDefExt2(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_LINKLAYERDOWN_1, "CRawIPFlow %08x:\tLinkLayerDown(aError %d)", (TUint)this, aError); - + _LOG_L1C3(_L8("CRawIPFlow %08x:\tLinkLayerDown(aError %d)"), this, aError); __PACKETLOG_DELETE; - + if (iStopping) { iLastRequestOriginator.ReplyTo(Id(), TCFDataClient::TStopped(aError).CRef()); @@ -220,7 +217,7 @@ * @param aAction The action to take: disconnect or reconnect */ { - OstTraceDefExt2(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_STOPFLOW_1, "CRawIPFlow %08x:\tStopFlow(aError %d)", (TUint)this, aError); + _LOG_L1C3(_L8("CRawIPFlow %08x:\tStopFlow(aError %d)"), this, aError); __PACKETLOG_DELETE; iStopping = ETrue; ShutDown(MControllerObserver::EInitialised, aError); @@ -236,7 +233,9 @@ * @return MLowerDataSender::TSendResult */ { - OstTraceDefExt3(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_SENDPACKET_1, "CRawIPFlow %08x:\tSendPacket(): length=%d, blocked=%d", (TUint)this, aPdu.Length() - aPdu.First()->Length(),iBlocked); + _LOG_L1C3(_L8("CRawIPFlow %08x:\tSendPacket(): length=%d"), + this, aPdu.Length() - aPdu.First()->Length()); + __PACKETLOG_WRITE_PACKET(aPdu, 0); return iBcaController->Send(aPdu); } @@ -250,12 +249,13 @@ * @param aPdu The incoming packet */ { - OstTraceDefExt2(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_PROCESS_1, "CRawIPFlow %08x:\tProcess() [aPdu length=%d]",(TUint)this, aPdu.Length() - aPdu.First()->Length()); + _LOG_L1C3(_L8("CRawIPFlow %08x:\tProcess() [aPdu length=%d]"), + this, aPdu.Length() - aPdu.First()->Length()); // If the packet has zero or negative length, bin it. if ((aPdu.Length() - aPdu.First()->Length()) <= 0) { - OstTraceDef0(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_PROCESS_2, "Dumped packet: illegal length"); + _LOG_L1C1(_L8("Dumped packet: illegal length")); aPdu.Free(); return; } @@ -269,10 +269,11 @@ else { // The protocol didn't want the packet, so bin it. - OstTraceDef1(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_PROCESS_3, "Packet was not processed: freeing (protocol code: %X)",aProtocolCode); + _LOG_L1C2(_L8("Packet was not processed: freeing (protocol code: %X)"), + aProtocolCode); if (iBinder == NULL) { - OstTraceDef1(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_PROCESS_4, "CRawIPFlow %08x:\tProcess(): NOTE: Binder not present", this); + _LOG_L1C2(_L8("CRawIPFlow %08x:\tProcess(): NOTE: Binder not present"), this); } aPdu.Free(); } @@ -283,7 +284,7 @@ * Notifies the protocol interface that it can resume sending packets. */ { - OstTraceDef1(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_RESUMESENDING_1, "CRawIPFlow %08x:\tResumeSending()", this); + _LOG_L1C2(_L8("CRawIPFlow %08x:\tResumeSending()"), this); if (iBinder) { @@ -291,7 +292,7 @@ } else { - OstTraceDef1(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_RESUMESENDING_2, "CRawIPFlow %08x:\tResumeSending(): NOTE: Binder not present", this); + _LOG_L1C2(_L8("CRawIPFlow %08x:\tResumeSending(): NOTE: Binder not present"), this); } } @@ -306,11 +307,12 @@ * @param aError A possible error */ { - OstTraceDefExt3(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_INITIALISEL_1, "CRawIPFlow %08x:\tInitialiseL(aState %d, aError %d)",(TUint)this, aState, aError); + _LOG_L1C4(_L8("CRawIPFlow %08x:\tInitialiseL(aState %d, aError %d)"), + this, aState, aError); if (aError != KErrNone) { - OstTraceDef1(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_INITIALISEL_2, " *** FAILED to initialise NIF *** Error =%d",aError); + _LOG_L2C2(_L8(" *** FAILED to initialise NIF *** Error =%d"),aError); // Initialise shutdown sequence switch (aState) @@ -319,7 +321,7 @@ ShutDown(MControllerObserver::EInitialised, aError); break; default: - OstTraceDefExt2(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_INITIALISEL_3, "ERROR CRawIPFlow: Unknown state:%d in NIF: %S", aState, KNifName); + _LOG_L2C3(_L8("ERROR CRawIPFlow: Unknown state:%d in NIF: %S"), aState, &KNifName); User::Leave(KErrUnknown); break; } @@ -334,13 +336,13 @@ GetBinder()->UpdateContextConfigL(*iAgentProvision->iGprsConfig); GetBinder()->UpdateConnectionSpeed(iAgentProvision->iConnectionSpeed); - OstTraceDefExt1(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_INITIALISEL_4, "Port details %S", iProvision->GetPortName()); + _LOG_L1C2(_L8("Port details %S"), &iProvision->GetPortName()); iBcaController->SetPort(iProvision->GetPortName()); - OstTraceDefExt2(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_INITIALISEL_5, "bcaName details %S,%S",iProvision->GetBCAStack(), iProvision->GetBCAName()); + _LOG_L1C3(_L8("bcaName details %S,%S"),&iProvision->GetBCAStack(), &iProvision->GetBCAName()); iBcaController->SetBcaStackAndName(iProvision->GetBCAStack(), iProvision->GetBCAName()); - OstTraceDef1(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_INITIALISEL_6, "IAP ID details %u", iProvision->GetIAPid()); + _LOG_L1C2(_L8("IAP ID details %u"), iProvision->GetIAPid()); iBcaController->SetIapId(iProvision->GetIAPid()); UpdateContextState(RPacketContext::EStatusActive, KErrNone); @@ -349,11 +351,11 @@ } break; case MControllerObserver::EBcaController: - OstTraceDef0(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_INITIALISEL_7, " ***** NIF INITIALISED *****"); + _LOG_L1C1(_L8(" ***** NIF INITIALISED *****")); LinkLayerUp(); break; default: - OstTraceDefExt2(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_INITIALISEL_8, "ERROR CRawIPFlow: Unknown state:%d in NIF: %S", aState, KNifName); + _LOG_L2C3(_L8("ERROR CRawIPFlow: Unknown state:%d in NIF: %S"), aState, &KNifName); User::Leave(KErrUnknown); break; } @@ -369,7 +371,8 @@ * @param aError A possible error (only during initialisation) */ { - OstTraceDefExt3(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_SHUTDOWN_1, "CRawIPFlow %08x:\tShutDown(aState %d, aError %d)",(TUint)this, aState, aError); + _LOG_L1C4(_L8("CRawIPFlow %08x:\tShutDown(aState %d, aError %d)"), + this, aState, aError); if (aError != KErrNone) { @@ -388,9 +391,8 @@ LinkLayerDown(iInitError); break; default: - OstTraceDef0(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_SHUTDOWN_2, "ERROR CRawIPFlow: Unknown Shutdown step"); - OstTraceDefExt2(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_SHUTDOWN_3, "PANIC: %S %d", KNifName, KNifUnknownShutDownState); - User::Panic(KNifName,KNifUnknownShutDownState); + _LOG_L2C1(_L8("ERROR CRawIPFlow: Unknown Shutdown step")); + _BTT_PANIC(KNifName,KNifUnknownShutDownState); break; } } @@ -424,7 +426,7 @@ * @param aError A possible error */ { - OstTraceDefExt2(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_UPDATECONTEXTSTATE_1, "CRawIPFlow %08x:\tUpdateContextState(aState %d)",(TUint) this, aState); + _LOG_L1C3(_L8("CRawIPFlow %08x:\tUpdateContextState(aState %d)"), this, aState); // Note that we do not need to close the Flow down if there's been an // error, as the context state machine will do this for us. @@ -449,23 +451,25 @@ MLowerControl* CRawIPFlow::GetControlL(const TDesC8& aProtocol) { - - OstTraceDefExt2(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_GETCONTROLL_1, "CRawIPFlow %08x:\tGetControlL(aProtocol %s)", (TUint)this, aProtocol); - +#ifdef __BTT_LOGGING__ + //TBuf8<256> debugBuffer; + //debugBuffer.Copy(aProtocol); + _LOG_L1C3(_L8("CRawIPFlow %08x:\tGetControlL(aProtocol %S)"), this, &aProtocol); +#endif // IPv4 and ICMP Protocols if (aProtocol.CompareF(KDescIp()) == 0 || aProtocol.CompareF(KDescIcmp()) == 0) { if (!iBinder) { - iBinder = new (ELeave) CIPv4Binder(*this); + iBinder = new (ELeave) CIPv4Binder(*this, iTheLogger); #ifdef RAWIP_HEADER_APPENDED_TO_PACKETS iBcaController->SetType(KIp4FrameType); #endif // RAWIP_HEADER_APPENDED_TO_PACKETS } else { - OstTraceDef1(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_GETCONTROLL_2, "CRawIPFlow %08x:\tGetControlL(): IPv4 binder already exists", this); + _LOG_L1C2(_L8("CRawIPFlow %08x:\tGetControlL(): IPv4 binder already exists"), this); } } // IPv6 Protocol @@ -473,14 +477,14 @@ { if (!iBinder) { - iBinder = new (ELeave) CIPv6Binder(*this); + iBinder = new (ELeave) CIPv6Binder(*this, iTheLogger); #ifdef RAWIP_HEADER_APPENDED_TO_PACKETS iBcaController->SetType(KIp6FrameType); #endif // RAWIP_HEADER_APPENDED_TO_PACKETS } else { - OstTraceDef1(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_GETCONTROLL_3, "CRawIPFlow %08x:\tGetControlL(): IPv6 binder already exists", this); + _LOG_L1C2(_L8("CRawIPFlow %08x:\tGetControlL(): IPv6 binder already exists"), this); } } else @@ -513,7 +517,7 @@ void CRawIPFlow::Unbind(MUpperDataReceiver* aUpperReceiver, MUpperControl* aUpperControl) { - OstTraceDef1(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_UNBIND_1, "CRawIPFlow %08x:\tUnbind()", this); + _LOG_L1C2(_L8("CRawIPFlow %08x:\tUnbind()"), this); if (iBinder) { @@ -636,6 +640,7 @@ //doesn't notice anything. It does that by swapping the //flows below the binders. CBinderBase* localBinder = iBinder; + CBttLogger* logger = localBinder->iTheLogger; TBinderControlProxy* localBinderControl = iBinderControl; iBinder = otherFlow->iBinder; @@ -647,6 +652,7 @@ otherFlow->iBinderControl->iFlow = otherFlow; iBinderControl->iFlow = this; + iBinder->iTheLogger = logger; iSubConnectionProvider.Close(); iSubConnectionProvider.Open(address_cast(rejoinMsg.iNodeId)); @@ -720,7 +726,7 @@ @param aData provisioning pointer from message */ { - OstTraceDef1(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_PROVISIONCONFIG_1, "CRawIPFlow %08x:\tProvisionConfig()", this); + _LOG_L1C2(_L8("CRawIPFlow %08x:\tProvisionConfig()"), this); AccessPointConfig().Close(); AccessPointConfig().Open(aConfigData); @@ -737,7 +743,7 @@ { if (iProvision == NULL) { - OstTraceDef0(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_DYNAMICPROVISIONCONFIGL_1, "CRawIPFlow:\tProvisionConfigL() - CBCAProvision config incomplete"); + _LOG_L1C1(_L8("CRawIPFlow:\tProvisionConfigL() - CBCAProvision config incomplete")); iProvisionError = KErrCorrupt; return; } @@ -755,7 +761,7 @@ STypeId::CreateSTypeId(CIPConfig::EUid, CIPConfig::ETypeId))); if (wcdmaIpProvision == NULL) { - OstTraceDef1(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_DYNAMICPROVISIONCONFIGL_2, "CRawIPFlow %08x:\tDynamicProvisionConfigL() - WCDMA config incomplete", this); + _LOG_L1C2(_L8("CRawIPFlow %08x:\tDynamicProvisionConfigL() - WCDMA config incomplete"), this); iProvisionError = KErrCorrupt; return; } @@ -783,13 +789,13 @@ some historical understanding. */ { - OstTraceDefExt2(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_NOTIFICATION_1, "CRawIPFlow %08x:\tNotification(aEvent %d)", (TUint)this, aEvent); + _LOG_L1C3(_L8("CRawIPFlow %08x:\tNotification(aEvent %d)"), this, aEvent); switch (aEvent) { - case EAgentToNifEventTypeDisableTimers: //GPRS suspension - { - OstTraceDef0(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_NOTIFICATION_2, "CRawIPFlow::Received Suspend from Agent..."); + case EAgentToNifEventTypeDisableTimers: //GPRS suspension + { + _LOG_L1C1(_L8("CRawIPFlow::Received Suspend from Agent...")); // Let the BCA controller know that data can no longer be sent over // the PDP context. @@ -800,7 +806,7 @@ case EAgentToNifEventTypeEnableTimers: //GPRS resumption { - OstTraceDef0(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_NOTIFICATION_3, "CRawIPFlow::Received Resume from Agent..."); + _LOG_L1C1(_L8("CRawIPFlow::Received Resume from Agent...")); iBcaController->ResumeSending(); break; @@ -808,13 +814,13 @@ case (EAgentToNifEventTypeDisableConnection) : { // This is handled by NIFMAN and passed to Flow as a Stop() call - OstTraceDef0(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_NOTIFICATION_4, "CRawIPFlow::Received Disable connection from Agent..."); + _LOG_L1C1(_L8("CRawIPFlow::Received Disable connection from Agent...")); break; } default : { - OstTraceDef1(OST_TRACE_CATEGORY_DEBUG, TRACE_INTERNALS, CRAWIPFLOW_NOTIFICATION_5, "CRawIPFlow::Received Notification [%d] from Agent...", aEvent); + _LOG_L1C2(_L8("CRawIPFlow::Received Notification [%d] from Agent..."), aEvent); break; } }//endswitch