From 6043cd8f1bdcb682c4bd68e56443a3fa3d8f3d2f Mon Sep 17 00:00:00 2001 From: Abtin Keshavarzian Date: Tue, 25 Apr 2017 10:24:58 -0700 Subject: [PATCH] Add/Update logs in `MeshForwarder` class (#1649) This commit contains the following changes: - Adds new logs when a new message is being prepared for indirect tx to a sleepy child. - Adds new logs when an Ipv6 message being dropped from reassembly list due to reassembly timeout or missing fragments (in case of MTD). --- include/openthread/types.h | 5 ++ src/core/common/logging.cpp | 4 ++ src/core/thread/mesh_forwarder.cpp | 105 ++++++++++++++++++++++++----- src/core/thread/mesh_forwarder.hpp | 10 +-- src/core/thread/topology.hpp | 21 ++++++ 5 files changed, 125 insertions(+), 20 deletions(-) diff --git a/include/openthread/types.h b/include/openthread/types.h index 8a0e5c682..7b5b8832b 100644 --- a/include/openthread/types.h +++ b/include/openthread/types.h @@ -194,6 +194,11 @@ typedef enum ThreadError */ kThreadError_Duplicated = 31, + /** + * Message is being dropped from reassembly list due to timeout. + */ + kThreadError_ReassemblyTimeout = 32, + kThreadError_Error = 255, } ThreadError; diff --git a/src/core/common/logging.cpp b/src/core/common/logging.cpp index e499e51db..04b41049f 100644 --- a/src/core/common/logging.cpp +++ b/src/core/common/logging.cpp @@ -393,6 +393,10 @@ const char *otThreadErrorToString(ThreadError aError) retval = "Duplicated"; break; + case kThreadError_ReassemblyTimeout: + retval = "ReassemblyTimeout"; + break; + case kThreadError_Error: retval = "GenericError"; break; diff --git a/src/core/thread/mesh_forwarder.cpp b/src/core/thread/mesh_forwarder.cpp index 5863570fd..452b9720f 100644 --- a/src/core/thread/mesh_forwarder.cpp +++ b/src/core/thread/mesh_forwarder.cpp @@ -497,6 +497,13 @@ Message *MeshForwarder::GetIndirectTransmission(Child &aChild) aChild.SetIndirectFragmentOffset(0); aChild.ResetIndirectTxAttempts(); + if (message != NULL) + { + Mac::Address macAddr; + + LogIp6Message(kMessagePrepareIndirect, *message, &aChild.GetMacAddress(macAddr), kThreadError_None); + } + return message; } @@ -1528,7 +1535,7 @@ void MeshForwarder::HandleSentFrame(Mac::Frame &aFrame, ThreadError aError) if (mMessageNextOffset >= mSendMessage->GetLength()) { - LogIp6Message(kMessageTransmit, *mSendMessage, macDest, aError); + LogIp6Message(kMessageTransmit, *mSendMessage, &macDest, aError); } if (mSendMessage->GetDirectTransmission() == false && mSendMessage->IsChildPending() == false) @@ -1891,6 +1898,9 @@ void MeshForwarder::ClearReassemblyList(void) { next = message->GetNext(); mReassemblyList.Dequeue(*message); + + LogIp6Message(kMessageDrop, *message, NULL, kThreadError_NoFrameReceived); + message->Free(); } } @@ -1917,6 +1927,9 @@ void MeshForwarder::HandleReassemblyTimer() else { mReassemblyList.Dequeue(*message); + + LogIp6Message(kMessageDrop, *message, NULL, kThreadError_ReassemblyTimeout); + message->Free(); } } @@ -1972,7 +1985,7 @@ exit: ThreadError MeshForwarder::HandleDatagram(Message &aMessage, const ThreadMessageInfo &aMessageInfo, const Mac::Address &aMacSource) { - LogIp6Message(kMessageReceive, aMessage, aMacSource, kThreadError_None); + LogIp6Message(kMessageReceive, aMessage, &aMacSource, kThreadError_None); return mNetif.GetIp6().HandleDatagram(aMessage, &mNetif, mNetif.GetInterfaceId(), &aMessageInfo, false); } @@ -2008,13 +2021,16 @@ void MeshForwarder::HandleDataPollTimeout(void *aContext) #if (OPENTHREAD_CONFIG_LOG_LEVEL >= OPENTHREAD_LOG_LEVEL_INFO) && (OPENTHREAD_CONFIG_LOG_MAC == 1) -void MeshForwarder::LogIp6Message(MessageAction aAction, const Message &aMessage, const Mac::Address &aMacAddress, +void MeshForwarder::LogIp6Message(MessageAction aAction, const Message &aMessage, const Mac::Address *aMacAddress, ThreadError aError) { uint16_t checksum = 0; Ip6::Header ip6Header; Ip6::IpProto protocol; char stringBuffer[Ip6::Address::kIp6AddressStringSize]; + const char *actionText; + const char *priorityText; + bool shouldLogSrcDstAddresses = true; VerifyOrExit(aMessage.GetType() == Message::kTypeIp6); @@ -2029,8 +2045,11 @@ void MeshForwarder::LogIp6Message(MessageAction aAction, const Message &aMessage { Ip6::UdpHeader udpHeader; - VerifyOrExit(sizeof(udpHeader) == aMessage.Read(sizeof(ip6Header), sizeof(udpHeader), &udpHeader)); - checksum = udpHeader.GetChecksum(); + if (sizeof(udpHeader) == aMessage.Read(sizeof(ip6Header), sizeof(udpHeader), &udpHeader)) + { + checksum = udpHeader.GetChecksum(); + } + break; } @@ -2038,8 +2057,11 @@ void MeshForwarder::LogIp6Message(MessageAction aAction, const Message &aMessage { Ip6::TcpHeader tcpHeader; - VerifyOrExit(sizeof(tcpHeader) == aMessage.Read(sizeof(ip6Header), sizeof(tcpHeader), &tcpHeader)); - checksum = tcpHeader.GetChecksum(); + if (sizeof(tcpHeader) == aMessage.Read(sizeof(ip6Header), sizeof(tcpHeader), &tcpHeader)) + { + checksum = tcpHeader.GetChecksum(); + } + break; } @@ -2047,30 +2069,81 @@ void MeshForwarder::LogIp6Message(MessageAction aAction, const Message &aMessage break; } + switch (aAction) + { + case kMessageReceive: + actionText = "Received"; + break; + + case kMessageTransmit: + actionText = (aError == kThreadError_None) ? "Sent" : "Failed to send"; + break; + + case kMessagePrepareIndirect: + actionText = "Preping indir tx"; + shouldLogSrcDstAddresses = false; + break; + + case kMessageDrop: + actionText = "Dropping"; + break; + + default: + actionText = ""; + break; + } + + switch (aMessage.GetPriority()) + { + case Message::kPriorityHigh: + priorityText = "high"; + break; + + case Message::kPriorityMedium: + priorityText = "medium"; + break; + + case Message::kPriorityLow: + priorityText = "low"; + break; + + case Message::kPriorityVeryLow: + priorityText = "verylow"; + break; + + default: + priorityText = "unknown"; + break; + } + otLogInfoMac( GetInstance(), - "%s IPv6 %s msg, len:%d, chksum:%04x, %s:%s, sec:%s%s%s", - (aAction == kMessageReceive) ? "Rx" : ((aError == kThreadError_None) ? "Tx" : "Failed to Tx"), + "%s IPv6 %s msg, len:%d, chksum:%04x%s%s, sec:%s%s%s, prio:%s", + actionText, Ip6::Ip6::IpProtoToString(protocol), aMessage.GetLength(), checksum, - (aAction == kMessageReceive) ? "from" : "to", - aMacAddress.ToString(stringBuffer, sizeof(stringBuffer)), + (aMacAddress == NULL) ? "" : ((aAction == kMessageReceive) ? ", from:" : ", to:"), + (aMacAddress == NULL) ? "" : aMacAddress->ToString(stringBuffer, sizeof(stringBuffer)), aMessage.IsLinkSecurityEnabled() ? "yes" : "no", (aError == kThreadError_None) ? "" : ", error:", - (aError == kThreadError_None) ? "" : otThreadErrorToString(aError) + (aError == kThreadError_None) ? "" : otThreadErrorToString(aError), + priorityText ); - otLogInfoMac(GetInstance(), "src: %s", ip6Header.GetSource().ToString(stringBuffer, sizeof(stringBuffer))); - otLogInfoMac(GetInstance(), "dst: %s", ip6Header.GetDestination().ToString(stringBuffer, sizeof(stringBuffer))); + if (shouldLogSrcDstAddresses) + { + otLogInfoMac(GetInstance(), "src: %s", ip6Header.GetSource().ToString(stringBuffer, sizeof(stringBuffer))); + otLogInfoMac(GetInstance(), "dst: %s", ip6Header.GetDestination().ToString(stringBuffer, sizeof(stringBuffer))); + } exit: return; } -#else // #if OPENTHREAD_CONFIG_LOG_LEVEL >= OPENTHREAD_LOG_LEVEL_INFO +#else // #if (OPENTHREAD_CONFIG_LOG_LEVEL >= OPENTHREAD_LOG_LEVEL_INFO) && (OPENTHREAD_CONFIG_LOG_MAC == 1) -void MeshForwarder::LogIp6Message(MessageAction, const Message &, const Mac::Address &, ThreadError) +void MeshForwarder::LogIp6Message(MessageAction, const Message &, const Mac::Address *, ThreadError) { } diff --git a/src/core/thread/mesh_forwarder.hpp b/src/core/thread/mesh_forwarder.hpp index 12db81c3e..bdebe74ab 100644 --- a/src/core/thread/mesh_forwarder.hpp +++ b/src/core/thread/mesh_forwarder.hpp @@ -243,10 +243,12 @@ private: kMaxPollTriggeredTxAttempts = OPENTHREAD_CONFIG_MAX_TX_ATTEMPTS_INDIRECT_POLLS, }; - enum MessageAction ///< Defines the action parameter in `LogMessageInfo()` method. + enum MessageAction ///< Defines the action parameter in `LogMessageInfo()` method. { - kMessageReceive, ///< Indicates that the message was received. - kMessageTransmit, ///< Indicates that the message was sent. + kMessageReceive, ///< Indicates that the message was received. + kMessageTransmit, ///< Indicates that the message was sent. + kMessagePrepareIndirect, ///< Indicates that the message is being prepared for indirect tx. + kMessageDrop, ///< Indicates that the message is being dropped from reassembly list. }; ThreadError CheckReachability(uint8_t *aFrame, uint8_t aFrameLength, @@ -294,7 +296,7 @@ private: ThreadError AddSrcMatchEntry(Child &aChild); void ClearSrcMatchEntry(Child &aChild); - void LogIp6Message(MessageAction aAction, const Message &aMessage, const Mac::Address &aMacAddress, + void LogIp6Message(MessageAction aAction, const Message &aMessage, const Mac::Address *aMacAddress, ThreadError aError); ThreadNetif &mNetif; diff --git a/src/core/thread/topology.hpp b/src/core/thread/topology.hpp index 52cf21559..0cbc6d402 100644 --- a/src/core/thread/topology.hpp +++ b/src/core/thread/topology.hpp @@ -626,6 +626,27 @@ public: */ void SetRequestTlv(uint8_t aIndex, uint8_t aType) { mRequestTlvs[aIndex] = aType; } + /** + * This method gets the mac address of child (either rloc16 or extended address depending on `UseShortAddress` flag). + * + * @param[out] aMacAddress A reference to a mac address object to which the child's address is copied. + * + * @returns A (const) reference to the mac address @a aMacAddress. + * + */ + const Mac::Address &GetMacAddress(Mac::Address &aMacAddress) const { + if (mUseShortAddress) { + aMacAddress.mShortAddress = GetRloc16(); + aMacAddress.mLength = sizeof(aMacAddress.mShortAddress); + } + else { + aMacAddress.mExtAddress = GetExtAddress(); + aMacAddress.mLength = sizeof(aMacAddress.mExtAddress); + } + + return aMacAddress; + } + private: Ip6::Address mIp6Address[kMaxIp6AddressPerChild]; ///< Registered IPv6 addresses uint32_t mTimeout; ///< Child timeout