[mesh-forwarder] update LogMessage to use NOTE level for failure/error cases (#2836)

This commit also contains
- Adding `Instance::GetLogLevel()` to get current log level on
  device.
- Adding new `otLogMac()` macro to log at MAC region with a run-time
  given log level.
This commit is contained in:
Abtin Keshavarzian
2018-06-29 13:00:53 -05:00
committed by Jonathan Hui
parent 38e7b30ef7
commit fdb3d0ef58
7 changed files with 182 additions and 49 deletions
@@ -442,6 +442,11 @@
// USESUFFIX(otLogDebgMacErr, ", %!otError!", EXP);
// end_wpp
// begin_wpp config
// USEPREFIX (otLogMac, "[%p]MAC%!SPACE!", &CTX);
// otLogMac{LEVEL=TRACE_LEVEL_INFORMATION,FLAGS=OT_MAC}(CTX, EXP, MSG, ...);
// end_wpp
// ==CORE==
// begin_wpp config
+17
View File
@@ -194,6 +194,23 @@ public:
void SetDynamicLogLevel(otLogLevel aLogLevel) { mLogLevel = aLogLevel; }
#endif
/**
* This method returns the active log level.
*
* @returns The log level.
*
*/
otLogLevel GetLogLevel(void) const
#if OPENTHREAD_CONFIG_ENABLE_DYNAMIC_LOG_LEVEL
{
return GetDynamicLogLevel();
}
#else
{
return static_cast<otLogLevel>(OPENTHREAD_CONFIG_LOG_LEVEL);
}
#endif
#if OPENTHREAD_MTD || OPENTHREAD_FTD
/**
* This method finalizes the OpenThread instance.
+34
View File
@@ -327,6 +327,40 @@ const char *otThreadErrorToString(otError aError)
return retval;
}
const char *otLogLevelToPrefixString(otLogLevel aLogLevel)
{
const char *retval = "";
switch (aLogLevel)
{
case OT_LOG_LEVEL_NONE:
retval = _OT_LEVEL_NONE_PREFIX;
break;
case OT_LOG_LEVEL_CRIT:
retval = _OT_LEVEL_CRIT_PREFIX;
break;
case OT_LOG_LEVEL_WARN:
retval = _OT_LEVEL_WARN_PREFIX;
break;
case OT_LOG_LEVEL_NOTE:
retval = _OT_LEVEL_NOTE_PREFIX;
break;
case OT_LOG_LEVEL_INFO:
retval = _OT_LEVEL_INFO_PREFIX;
break;
case OT_LOG_LEVEL_DEBG:
retval = _OT_LEVEL_DEBG_PREFIX;
break;
}
return retval;
}
#if OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_NONE
/* this provides a stub, incase something uses the function */
void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...)
+39 -6
View File
@@ -71,12 +71,12 @@ extern "C" {
#define _OT_LEVEL_DEBG_PREFIX "[DEBG]"
#define _OT_REGION_SUFFIX ": "
#else
#define _OT_LEVEL_NONE_PREFIX
#define _OT_LEVEL_CRIT_PREFIX
#define _OT_LEVEL_WARN_PREFIX
#define _OT_LEVEL_NOTE_PREFIX
#define _OT_LEVEL_INFO_PREFIX
#define _OT_LEVEL_DEBG_PREFIX
#define _OT_LEVEL_NONE_PREFIX ""
#define _OT_LEVEL_CRIT_PREFIX ""
#define _OT_LEVEL_WARN_PREFIX ""
#define _OT_LEVEL_NOTE_PREFIX ""
#define _OT_LEVEL_INFO_PREFIX ""
#define _OT_LEVEL_DEBG_PREFIX ""
#define _OT_REGION_SUFFIX
#endif
@@ -789,6 +789,18 @@ extern "C" {
* @param[in] ... Arguments for the format specification.
*
*/
/**
* @def otLogMac
*
* This method generates a log with a given log level for the MAC region.
*
* @param[in] aInstance A reference to the OpenThread instance.
* @param[in] aLogLevel A log level.
* @param[in] aFormat A pointer to the format string.
* @param[in] ... Arguments for the format specification.
*
*/
#if OPENTHREAD_CONFIG_LOG_MAC == 1
#define otLogCritMac(aInstance, aFormat, ...) \
otLogCrit(&aInstance, OT_LOG_REGION_MAC, _OT_REGION_MAC_PREFIX aFormat, ##__VA_ARGS__)
@@ -803,6 +815,16 @@ extern "C" {
#define otLogDebgMacErr(aInstance, aError, aFormat, ...) \
otLogWarn(aInstance, OT_LOG_REGION_MAC, _OT_REGION_MAC_PREFIX "Error %s: " aFormat, otThreadErrorToString(aError), \
##__VA_ARGS__)
#define otLogMac(aInstance, aLogLevel, aFormat, ...) \
do \
{ \
if (aInstance.GetLogLevel() >= aLogLevel) \
{ \
_otLogFormatter(&aInstance, aLogLevel, OT_LOG_REGION_MAC, "%s" _OT_REGION_MAC_PREFIX aFormat, \
otLogLevelToPrefixString(aLogLevel), ##__VA_ARGS__); \
} \
} while (false)
#else
#define otLogCritMac(aInstance, aFormat, ...)
#define otLogWarnMac(aInstance, aFormat, ...)
@@ -810,6 +832,7 @@ extern "C" {
#define otLogInfoMac(aInstance, aFormat, ...)
#define otLogDebgMac(aInstance, aFormat, ...)
#define otLogDebgMacErr(aInstance, aError, aFormat, ...)
#define otLogMac(aInstance, aLogLevel, aFormat, ...)
#endif
/**
@@ -2072,6 +2095,16 @@ void otDump(otInstance * aIntsance,
const void * aBuf,
const size_t aLength);
/**
* This function converts a log level to a prefix string for appending to log message.
*
* @param[in] aLogLevel A log level.
*
* @returns A C string representing the log level.
*
*/
const char *otLogLevelToPrefixString(otLogLevel aLogLevel);
/**
* Local/private macro to format the log message
*/
+49 -22
View File
@@ -1486,7 +1486,7 @@ void MeshForwarder::HandleDataPollTimeout(Mac::Receiver &aReceiver)
aReceiver.GetOwner<MeshForwarder>().GetDataPollManager().HandlePollTimeout();
}
#if (OPENTHREAD_CONFIG_LOG_LEVEL >= OT_LOG_LEVEL_INFO) && (OPENTHREAD_CONFIG_LOG_MAC == 1)
#if (OPENTHREAD_CONFIG_LOG_LEVEL >= OT_LOG_LEVEL_NOTE) && (OPENTHREAD_CONFIG_LOG_MAC == 1)
otError MeshForwarder::ParseIp6UdpTcpHeader(const Message &aMessage,
Ip6::Header & aIp6Header,
@@ -1595,28 +1595,32 @@ const char *MeshForwarder::MessagePriorityToString(const Message &aMessage)
}
#if OPENTHREAD_CONFIG_LOG_SRC_DST_IP_ADDRESSES
void MeshForwarder::LogIp6SourceDestAddresses(Ip6::Header &aIp6Header, uint16_t aSourcePort, uint16_t aDestPort)
void MeshForwarder::LogIp6SourceDestAddresses(Ip6::Header &aIp6Header,
uint16_t aSourcePort,
uint16_t aDestPort,
otLogLevel aLogLevel)
{
if (aSourcePort != 0)
{
otLogInfoMac(GetInstance(), "\tsrc:[%s]:%d", aIp6Header.GetSource().ToString().AsCString(), aSourcePort);
otLogMac(GetInstance(), aLogLevel, "\tsrc:[%s]:%d", aIp6Header.GetSource().ToString().AsCString(), aSourcePort);
}
else
{
otLogInfoMac(GetInstance(), "\tsrc:[%s]", aIp6Header.GetSource().ToString().AsCString());
otLogMac(GetInstance(), aLogLevel, "\tsrc:[%s]", aIp6Header.GetSource().ToString().AsCString());
}
if (aDestPort != 0)
{
otLogInfoMac(GetInstance(), "\tdst:[%s]:%d", aIp6Header.GetDestination().ToString().AsCString(), aDestPort);
otLogMac(GetInstance(), aLogLevel, "\tdst:[%s]:%d", aIp6Header.GetDestination().ToString().AsCString(),
aDestPort);
}
else
{
otLogInfoMac(GetInstance(), "\tdst:[%s]", aIp6Header.GetDestination().ToString().AsCString());
otLogMac(GetInstance(), aLogLevel, "\tdst:[%s]", aIp6Header.GetDestination().ToString().AsCString());
}
}
#else
void MeshForwarder::LogIp6SourceDestAddresses(Ip6::Header &, uint16_t, uint16_t)
void MeshForwarder::LogIp6SourceDestAddresses(Ip6::Header &, uint16_t, uint16_t, otLogLevel)
{
}
#endif
@@ -1624,7 +1628,8 @@ void MeshForwarder::LogIp6SourceDestAddresses(Ip6::Header &, uint16_t, uint16_t)
void MeshForwarder::LogIp6Message(MessageAction aAction,
const Message & aMessage,
const Mac::Address *aMacAddress,
otError aError)
otError aError,
otLogLevel aLogLevel)
{
Ip6::Header ip6Header;
uint16_t checksum;
@@ -1636,18 +1641,18 @@ void MeshForwarder::LogIp6Message(MessageAction aAction,
shouldLogRss = (aAction == kMessageReceive) || (aAction == kMessageReassemblyDrop);
otLogInfoMac(GetInstance(), "%s IPv6 %s msg, len:%d, chksum:%04x%s%s, sec:%s%s%s, prio:%s%s%s",
MessageActionToString(aAction, aError), Ip6::Ip6::IpProtoToString(ip6Header.GetNextHeader()),
aMessage.GetLength(), checksum,
(aMacAddress == NULL) ? "" : ((aAction == kMessageReceive) ? ", from:" : ", to:"),
(aMacAddress == NULL) ? "" : aMacAddress->ToString().AsCString(),
aMessage.IsLinkSecurityEnabled() ? "yes" : "no", (aError == OT_ERROR_NONE) ? "" : ", error:",
(aError == OT_ERROR_NONE) ? "" : otThreadErrorToString(aError), MessagePriorityToString(aMessage),
shouldLogRss ? ", rss:" : "", shouldLogRss ? aMessage.GetRssAverager().ToString().AsCString() : "");
otLogMac(GetInstance(), aLogLevel, "%s IPv6 %s msg, len:%d, chksum:%04x%s%s, sec:%s%s%s, prio:%s%s%s",
MessageActionToString(aAction, aError), Ip6::Ip6::IpProtoToString(ip6Header.GetNextHeader()),
aMessage.GetLength(), checksum,
(aMacAddress == NULL) ? "" : ((aAction == kMessageReceive) ? ", from:" : ", to:"),
(aMacAddress == NULL) ? "" : aMacAddress->ToString().AsCString(),
aMessage.IsLinkSecurityEnabled() ? "yes" : "no", (aError == OT_ERROR_NONE) ? "" : ", error:",
(aError == OT_ERROR_NONE) ? "" : otThreadErrorToString(aError), MessagePriorityToString(aMessage),
shouldLogRss ? ", rss:" : "", shouldLogRss ? aMessage.GetRssAverager().ToString().AsCString() : "");
if (aAction != kMessagePrepareIndirect)
{
LogIp6SourceDestAddresses(ip6Header, sourcePort, destPort);
LogIp6SourceDestAddresses(ip6Header, sourcePort, destPort, aLogLevel);
}
exit:
@@ -1659,28 +1664,50 @@ void MeshForwarder::LogMessage(MessageAction aAction,
const Mac::Address *aMacAddress,
otError aError)
{
otLogLevel logLevel = OT_LOG_LEVEL_INFO;
switch (aAction)
{
case kMessageReceive:
case kMessageTransmit:
case kMessagePrepareIndirect:
logLevel = (aError == OT_ERROR_NONE) ? OT_LOG_LEVEL_INFO : OT_LOG_LEVEL_NOTE;
break;
case kMessageDrop:
case kMessageReassemblyDrop:
case kMessageEvict:
logLevel = OT_LOG_LEVEL_NOTE;
break;
}
VerifyOrExit(GetInstance().GetLogLevel() >= logLevel);
switch (aMessage.GetType())
{
case Message::kTypeIp6:
LogIp6Message(aAction, aMessage, aMacAddress, aError);
LogIp6Message(aAction, aMessage, aMacAddress, aError, logLevel);
break;
#if OPENTHREAD_FTD
case Message::kType6lowpan:
LogMeshMessage(aAction, aMessage, aMacAddress, aError);
LogMeshMessage(aAction, aMessage, aMacAddress, aError, logLevel);
break;
#endif
default:
break;
}
exit:
return;
}
void MeshForwarder::LogFrame(const char *aActionText, const Mac::Frame &aFrame, otError aError)
{
if (aError != OT_ERROR_NONE)
{
otLogInfoMac(GetInstance(), "%s, aError:%s, %s", aActionText, otThreadErrorToString(aError),
otLogNoteMac(GetInstance(), "%s, aError:%s, %s", aActionText, otThreadErrorToString(aError),
aFrame.ToInfoString().AsCString());
}
else
@@ -1696,7 +1723,7 @@ void MeshForwarder::LogFragmentFrameDrop(otError aError,
const Lowpan::FragmentHeader &aFragmentHeader,
bool aIsSecure)
{
otLogInfoMac(GetInstance(),
otLogNoteMac(GetInstance(),
"Dropping rx frag frame, error:%s, len:%d, src:%s, dst:%s, tag:%d, offset:%d, dglen:%d, sec:%s",
otThreadErrorToString(aError), aFrameLength, aMacSource.ToString().AsCString(),
aMacDest.ToString().AsCString(), aFragmentHeader.GetDatagramTag(), aFragmentHeader.GetDatagramOffset(),
@@ -1709,7 +1736,7 @@ void MeshForwarder::LogLowpanHcFrameDrop(otError aError,
const Mac::Address &aMacDest,
bool aIsSecure)
{
otLogInfoMac(GetInstance(), "Dropping rx lowpan HC frame, error:%s, len:%d, src:%s, dst:%s, sec:%s",
otLogNoteMac(GetInstance(), "Dropping rx lowpan HC frame, error:%s, len:%d, src:%s, dst:%s, sec:%s",
otThreadErrorToString(aError), aFrameLength, aMacSource.ToString().AsCString(),
aMacDest.ToString().AsCString(), aIsSecure ? "yes" : "no");
}
+20 -7
View File
@@ -340,7 +340,7 @@ private:
const Mac::Address &aMacDest,
bool aIsSecure);
#if (OPENTHREAD_CONFIG_LOG_LEVEL >= OT_LOG_LEVEL_INFO) && (OPENTHREAD_CONFIG_LOG_MAC == 1)
#if (OPENTHREAD_CONFIG_LOG_LEVEL >= OT_LOG_LEVEL_NOTE) && (OPENTHREAD_CONFIG_LOG_MAC == 1)
const char *MessageActionToString(MessageAction aAction, otError aError);
const char *MessagePriorityToString(const Message &aMessage);
@@ -364,16 +364,29 @@ private:
otError aError,
uint16_t & aOffset,
Mac::Address & aMeshSource,
Mac::Address & aMeshDest);
Mac::Address & aMeshDest,
otLogLevel aLogLevel);
void LogMeshIpHeader(const Message & aMessage,
uint16_t aOffset,
const Mac::Address &aMeshSource,
const Mac::Address &aMeshDest);
void LogMeshMessage(MessageAction aAction, const Message &aMessage, const Mac::Address *aAddress, otError aError);
const Mac::Address &aMeshDest,
otLogLevel aLogLevel);
void LogMeshMessage(MessageAction aAction,
const Message & aMessage,
const Mac::Address *aAddress,
otError aError,
otLogLevel aLogLevel);
#endif
void LogIp6SourceDestAddresses(Ip6::Header &aIp6Header, uint16_t aSourcePort, uint16_t aDestPort);
void LogIp6Message(MessageAction aAction, const Message &aMessage, const Mac::Address *aAddress, otError aError);
#endif // #if (OPENTHREAD_CONFIG_LOG_LEVEL >= OT_LOG_LEVEL_INFO) && (OPENTHREAD_CONFIG_LOG_MAC == 1)
void LogIp6SourceDestAddresses(Ip6::Header &aIp6Header,
uint16_t aSourcePort,
uint16_t aDestPort,
otLogLevel aLogLevel);
void LogIp6Message(MessageAction aAction,
const Message & aMessage,
const Mac::Address *aAddress,
otError aError,
otLogLevel aLogLevel);
#endif // #if (OPENTHREAD_CONFIG_LOG_LEVEL >= OT_LOG_LEVEL_NOTE) && (OPENTHREAD_CONFIG_LOG_MAC == 1)
Mac::Receiver mMacReceiver;
Mac::Sender mMacSender;
+18 -14
View File
@@ -1051,7 +1051,7 @@ exit:
}
#endif // OPENTHREAD_ENABLE_SERVICE
#if (OPENTHREAD_CONFIG_LOG_LEVEL >= OT_LOG_LEVEL_INFO) && (OPENTHREAD_CONFIG_LOG_MAC == 1)
#if (OPENTHREAD_CONFIG_LOG_LEVEL >= OT_LOG_LEVEL_NOTE) && (OPENTHREAD_CONFIG_LOG_MAC == 1)
otError MeshForwarder::LogMeshFragmentHeader(MessageAction aAction,
const Message & aMessage,
@@ -1059,7 +1059,8 @@ otError MeshForwarder::LogMeshFragmentHeader(MessageAction aAction,
otError aError,
uint16_t & aOffset,
Mac::Address & aMeshSource,
Mac::Address & aMeshDest)
Mac::Address & aMeshDest,
otLogLevel aLogLevel)
{
otError error = OT_ERROR_FAILED;
bool hasFragmentHeader = false;
@@ -1083,8 +1084,8 @@ otError MeshForwarder::LogMeshFragmentHeader(MessageAction aAction,
shouldLogRss = (aAction == kMessageReceive) || (aAction == kMessageReassemblyDrop);
otLogInfoMac(
GetInstance(), "%s mesh frame, len:%d%s%s, msrc:%s, mdst:%s, hops:%d, frag:%s, sec:%s%s%s%s%s",
otLogMac(
GetInstance(), aLogLevel, "%s mesh frame, len:%d%s%s, msrc:%s, mdst:%s, hops:%d, frag:%s, sec:%s%s%s%s%s",
MessageActionToString(aAction, aError), aMessage.GetLength(),
(aMacAddress == NULL) ? "" : ((aAction == kMessageReceive) ? ", from:" : ", to:"),
(aMacAddress == NULL) ? "" : aMacAddress->ToString().AsCString(), aMeshSource.ToString().AsCString(),
@@ -1095,8 +1096,8 @@ otError MeshForwarder::LogMeshFragmentHeader(MessageAction aAction,
if (hasFragmentHeader)
{
otLogInfoMac(GetInstance(), "\tFrag tag:%04x, offset:%d, size:%d", fragmentHeader.GetDatagramTag(),
fragmentHeader.GetDatagramOffset(), fragmentHeader.GetDatagramSize());
otLogMac(GetInstance(), aLogLevel, "\tFrag tag:%04x, offset:%d, size:%d", fragmentHeader.GetDatagramTag(),
fragmentHeader.GetDatagramOffset(), fragmentHeader.GetDatagramSize());
VerifyOrExit(fragmentHeader.GetDatagramOffset() == 0);
}
@@ -1183,7 +1184,8 @@ exit:
void MeshForwarder::LogMeshIpHeader(const Message & aMessage,
uint16_t aOffset,
const Mac::Address &aMeshSource,
const Mac::Address &aMeshDest)
const Mac::Address &aMeshDest,
otLogLevel aLogLevel)
{
uint16_t checksum;
uint16_t sourcePort;
@@ -1193,10 +1195,10 @@ void MeshForwarder::LogMeshIpHeader(const Message & aMessage,
SuccessOrExit(DecompressIp6UdpTcpHeader(aMessage, aOffset, aMeshSource, aMeshDest, ip6Header, checksum, sourcePort,
destPort));
otLogInfoMac(GetInstance(), "\tIPv6 %s msg, chksum:%04x, prio:%s",
Ip6::Ip6::IpProtoToString(ip6Header.GetNextHeader()), checksum, MessagePriorityToString(aMessage));
otLogMac(GetInstance(), aLogLevel, "\tIPv6 %s msg, chksum:%04x, prio:%s",
Ip6::Ip6::IpProtoToString(ip6Header.GetNextHeader()), checksum, MessagePriorityToString(aMessage));
LogIp6SourceDestAddresses(ip6Header, sourcePort, destPort);
LogIp6SourceDestAddresses(ip6Header, sourcePort, destPort, aLogLevel);
exit:
return;
@@ -1205,13 +1207,15 @@ exit:
void MeshForwarder::LogMeshMessage(MessageAction aAction,
const Message & aMessage,
const Mac::Address *aMacAddress,
otError aError)
otError aError,
otLogLevel aLogLevel)
{
uint16_t offset;
Mac::Address meshSource;
Mac::Address meshDest;
SuccessOrExit(LogMeshFragmentHeader(aAction, aMessage, aMacAddress, aError, offset, meshSource, meshDest));
SuccessOrExit(
LogMeshFragmentHeader(aAction, aMessage, aMacAddress, aError, offset, meshSource, meshDest, aLogLevel));
// When log action is `kMessageTransmit` we do not include
// the IPv6 header info in the logs, as the same info is
@@ -1220,13 +1224,13 @@ void MeshForwarder::LogMeshMessage(MessageAction aAction,
VerifyOrExit(aAction != kMessageTransmit);
LogMeshIpHeader(aMessage, offset, meshSource, meshDest);
LogMeshIpHeader(aMessage, offset, meshSource, meshDest, aLogLevel);
exit:
return;
}
#endif // #if (OPENTHREAD_CONFIG_LOG_LEVEL >= OT_LOG_LEVEL_INFO) && (OPENTHREAD_CONFIG_LOG_MAC == 1)
#endif // #if (OPENTHREAD_CONFIG_LOG_LEVEL >= OT_LOG_LEVEL_NOTE) && (OPENTHREAD_CONFIG_LOG_MAC == 1)
} // namespace ot